This job view page is being replaced by Spyglass soon. Check out the new job view.
ResultFAILURE
Tests 0 failed / 0 succeeded
Started2022-08-07 03:02
Elapsed5m1s
Revisionrelease-0.3

No Test Failures!


Error lines from build-log.txt

... skipping 774 lines ...
I0807 03:04:20.380002    8466 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0807 03:04:20.381046    8466 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0807 03:04:20.381275    8466 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=39693
I0807 03:04:20.381533    8466 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0807 03:04:21.344148    8466 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" 
•I0807 03:04:21.359830    8466 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0807 03:04:21.361274    8466 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0807 03:04:21.361331    8466 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-960815327/tls.crt: no such file or directory"  


Ran 1 of 1 Specs in 16.272 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (16.27s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	53.059s
=== RUN   TestNewInitControlPlaneAdditionalFileEncodings
--- PASS: TestNewInitControlPlaneAdditionalFileEncodings (0.00s)
=== RUN   TestNewInitControlPlaneCommands
... skipping 316 lines ...
=== RUN   Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined
--- PASS: Test_clusterctlClient_GetProvidersConfig (0.00s)
    --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers (0.00s)
    --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined (0.00s)
=== RUN   Test_clusterctlClient_GetProviderComponents
=== RUN   Test_clusterctlClient_GetProviderComponents/Pass
=== RUN   Test_clusterctlClient_GetProviderComponents/Fail
--- PASS: Test_clusterctlClient_GetProviderComponents (0.00s)
    --- PASS: Test_clusterctlClient_GetProviderComponents/Pass (0.00s)
    --- PASS: Test_clusterctlClient_GetProviderComponents/Fail (0.00s)
=== RUN   Test_getComponentsByName_withEmptyVariables
--- PASS: Test_getComponentsByName_withEmptyVariables (0.00s)
=== RUN   Test_clusterctlClient_templateOptionsToVariables
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_template_options)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_env_variables)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_defaults_for_machine_counts)
... skipping 1398 lines ...
I0807 03:04:12.690303   10671 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0807 03:04:12.690365   10671 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0807 03:04:12.690303   10671 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
I0807 03:04:12.690408   10671 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machineset" 
I0807 03:04:12.690439   10671 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machineset" "worker count"=1
I0807 03:04:12.690460   10671 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
2022/08/07 03:04:12 http: TLS handshake error from 127.0.0.1:47780: EOF
=== RUN   TestClusterReconcilePhases
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infrastructure_ref_is_nil
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_error_if_unable_to_reconcile_infrastructure_ref
I0807 03:04:12.985462   10671 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"
I0807 03:04:12.989820   10671 cluster_controller_phases.go:76]  "msg"="Could not find external object for cluster, requeuing" "cluster"="test-cluster" "namespace"="test-namespace" "refGroupVersionKind"={"Group":"infrastructure.cluster.x-k8s.io","Version":"v1alpha3","Kind":"InfrastructureMachine"} "refName"="test"
... skipping 105 lines ...
    --- PASS: TestReconcileBootstrap/existing_machine,_machineset_owner_and_version_v1alpha2,_and_ownerref_updated (0.01s)
=== RUN   TestReconcileInfrastructure
=== RUN   TestReconcileInfrastructure/new_machine,_infrastructure_config_ready
I0807 03:04:13.150857   10671 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
I0807 03:04:13.154282   10671 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"
E0807 03:04:13.154832   10671 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
I0807 03:04:13.155494   10671 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
--- PASS: TestReconcileInfrastructure (0.01s)
    --- PASS: TestReconcileInfrastructure/new_machine,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machine_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestWatches
I0807 03:04:13.665792   10671 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0807 03:04:13.766845   10671 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0807 03:04:13.782062   10671 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-x7r5h" "namespace"="test-machine-watches-fnw7n" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0807 03:04:13.782165   10671 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0807 03:04:13.915414   10671 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-x7r5h" "namespace"="test-machine-watches-fnw7n" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0807 03:04:13.915501   10671 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0807 03:04:14.016247   10671 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-x7r5h" "namespace"="test-machine-watches-fnw7n" "noderef"="node-1"
E0807 03:04:14.029068   10671 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0807 03:04:14.029126   10671 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0807 03:04:14.095808   10671 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-x7r5h" "namespace"="test-machine-watches-fnw7n" "noderef"="node-1"
E0807 03:04:14.132372   10671 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-x7r5h\" in namespace \"test-machine-watches-fnw7n\", requeuing: requeue in 1s"  
E0807 03:04:14.167671   10671 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-x7r5h\" in namespace \"test-machine-watches-fnw7n\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-x7r5h\" in namespace \"test-machine-watches-fnw7n\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-x7r5h" "namespace"="test-machine-watches-fnw7n"
--- PASS: TestWatches (1.04s)
=== 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
I0807 03:04:14.392976   10671 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-gkkbb" "namespace"="test-machine-watches-fnw7n" "count"=1
I0807 03:04:14.393069   10671 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-gkkbb" "namespace"="test-machine-watches-fnw7n" "descendants"="Worker machines: machine-created-x7r5h" "indirect descendants count"=0
I0807 03:04:14.415864   10671 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-gkkbb" "namespace"="test-machine-watches-fnw7n" "count"=1
I0807 03:04:14.415945   10671 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-gkkbb" "namespace"="test-machine-watches-fnw7n" "descendants"="Worker machines: machine-created-x7r5h" "indirect descendants count"=0
I0807 03:04:15.168276   10671 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-gkkbb" "machine"="machine-created-x7r5h" "namespace"="test-machine-watches-fnw7n" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"2a416c93-a475-46c8-8353-eacc72ee3727","apiVersion":"v1"}
E0807 03:04:15.234300   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-x7r5h\" not found" "controller"="machine" "name"="machine-created-x7r5h" "namespace"="test-machine-watches-fnw7n"
E0807 03:04:16.422634   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-8sxzn\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-wktpd\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-wktpd: secrets \"machine-reconcile-wktpd-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-8sxzn" "namespace"="default"
I0807 03:04:17.423535   10671 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-wktpd" "machine"="machine-created-8sxzn" "namespace"="default" "cause"="noderef is nil" "node"=null
I0807 03:04:17.490704   10671 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-wktpd" "machine"="machine-created-8sxzn" "namespace"="default" "cause"="noderef is nil" "node"=null
I0807 03:04:17.541367   10671 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-wktpd" "machine"="machine-created-8sxzn" "namespace"="default" "cause"="noderef is nil" "node"=null
E0807 03:04:17.588512   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-8sxzn\" not found" "controller"="machine" "name"="machine-created-8sxzn" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.40s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.40s)
=== 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 16 lines ...
=== RUN   TestReconcileRequest
=== RUN   TestReconcileRequest/machine_should_be_created
I0807 03:04:17.621890   10671 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="created" "namespace"="default" "err"="cannot create a metadata client without a rest config"
=== RUN   TestReconcileRequest/machine_should_be_updated
I0807 03:04:17.628880   10671 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
E0807 03:04:17.647259   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-wktpd\" not found" "controller"="cluster" "name"="machine-reconcile-wktpd" "namespace"="default"
I0807 03:04:17.648109   10671 machine_controller.go:305]  "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="deleted" "namespace"="default" "cause"="noderef is nil" "node"=null
--- PASS: TestReconcileRequest (0.03s)
    --- PASS: TestReconcileRequest/machine_should_be_created (0.01s)
    --- PASS: TestReconcileRequest/machine_should_be_updated (0.02s)
    --- PASS: TestReconcileRequest/machine_should_be_deleted (0.01s)
=== RUN   TestMachineConditions
... skipping 107 lines ...
    --- PASS: TestMachineDeploymentSyncStatus/scaling_up (0.00s)
    --- PASS: TestMachineDeploymentSyncStatus/scaling_down (0.00s)
    --- PASS: TestMachineDeploymentSyncStatus/machine_set_failed (0.00s)
=== RUN   TestMachineHealthCheck_Reconcile
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist
I0807 03:04:17.846340   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g8txc" "namespace"="test-mhc-tkzch" 
E0807 03:04:17.870672   10671 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-f49z8\" not found"  "cluster"="test-mhc-tkzch/test-cluster-f49z8"
I0807 03:04:17.870890   10671 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
E0807 03:04:17.978452   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-g8txc\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-g8txc\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-g8txc" "namespace"="test-mhc-tkzch"
=== 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
I0807 03:04:18.978784   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g8txc" "namespace"="test-mhc-tkzch" 
I0807 03:04:18.978918   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-n9ldh" "namespace"="test-mhc-b26cn" 
I0807 03:04:18.978950   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-p7m96" "namespace"="test-mhc-ljvkd" 
I0807 03:04:18.978976   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d42gr" "namespace"="test-mhc-ftbp9" 
I0807 03:04:18.994477   10671 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0807 03:04:19.025874   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d42gr" "namespace"="test-mhc-ftbp9" 
I0807 03:04:19.045088   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d42gr" "namespace"="test-mhc-ftbp9" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
E0807 03:04:19.068800   10671 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-ftbp9/test-cluster-wnhgb"
E0807 03:04:19.071786   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-wnhgb\" not found" "controller"="cluster" "name"="test-cluster-wnhgb" "namespace"="test-mhc-ftbp9"
I0807 03:04:19.178165   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d76b9" "namespace"="test-mhc-spwbm" 
I0807 03:04:19.203129   10671 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0807 03:04:19.226450   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d76b9" "namespace"="test-mhc-spwbm" 
I0807 03:04:19.232477   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d76b9" "namespace"="test-mhc-spwbm" 
E0807 03:04:19.280633   10671 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-spwbm/test-cluster-cvszp"
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0807 03:04:19.294749   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d76b9" "namespace"="test-mhc-spwbm" 
I0807 03:04:19.433394   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sq9vk" "namespace"="test-mhc-8bt4l" 
inframachine created: test-mhc-machine-infra-62nsw
I0807 03:04:19.498516   10671 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-ztbcr
I0807 03:04:19.534989   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sq9vk" "namespace"="test-mhc-8bt4l" 
I0807 03:04:19.535401   10671 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-8bt4l/test-mhc-sq9vk/test-mhc-machine-ztbcr/"
I0807 03:04:19.564125   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sq9vk" "namespace"="test-mhc-8bt4l" 
I0807 03:04:19.564770   10671 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-8bt4l/test-mhc-sq9vk/test-mhc-machine-ztbcr/"
I0807 03:04:19.566915   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sq9vk" "namespace"="test-mhc-8bt4l" 
I0807 03:04:19.567628   10671 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-8bt4l/test-mhc-sq9vk/test-mhc-machine-ztbcr/"
I0807 03:04:19.580133   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sq9vk" "namespace"="test-mhc-8bt4l" 
I0807 03:04:19.581338   10671 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-8bt4l/test-mhc-sq9vk/test-mhc-machine-ztbcr/"
I0807 03:04:19.602624   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sq9vk" "namespace"="test-mhc-8bt4l" 
I0807 03:04:19.603519   10671 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-8bt4l/test-mhc-sq9vk/test-mhc-machine-ztbcr/"
I0807 03:04:19.605724   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sq9vk" "namespace"="test-mhc-8bt4l" 
I0807 03:04:19.607265   10671 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-8bt4l/test-mhc-sq9vk/test-mhc-machine-ztbcr/"
E0807 03:04:19.625786   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-tbjgr, got []"  "node"="test-mhc-node-tbjgr"
E0807 03:04:19.629137   10671 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-tbjgr"
node created: test-mhc-node-tbjgr
I0807 03:04:19.637696   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sq9vk" "namespace"="test-mhc-8bt4l" 
I0807 03:04:19.638311   10671 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-8bt4l/test-mhc-sq9vk/test-mhc-machine-ztbcr/"
I0807 03:04:19.649759   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sq9vk" "namespace"="test-mhc-8bt4l" 
inframachine created: test-mhc-machine-infra-n6kjc
I0807 03:04:19.656740   10671 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-ztbcr" "namespace"="test-mhc-8bt4l" "noderef"="test-mhc-node-tbjgr"
machine created: test-mhc-machine-zpqd2
I0807 03:04:19.672142   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sq9vk" "namespace"="test-mhc-8bt4l" 
I0807 03:04:19.683799   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sq9vk" "namespace"="test-mhc-8bt4l" 
... skipping 3 lines ...
I0807 03:04:19.698217   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sq9vk" "namespace"="test-mhc-8bt4l" 
I0807 03:04:19.701441   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sq9vk" "namespace"="test-mhc-8bt4l" 
I0807 03:04:19.703821   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sq9vk" "namespace"="test-mhc-8bt4l" 
I0807 03:04:19.706744   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sq9vk" "namespace"="test-mhc-8bt4l" 
I0807 03:04:19.708673   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sq9vk" "namespace"="test-mhc-8bt4l" 
I0807 03:04:19.715664   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sq9vk" "namespace"="test-mhc-8bt4l" 
I0807 03:04:19.719541   10671 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-8bt4l/test-mhc-sq9vk/test-mhc-machine-zpqd2/"
I0807 03:04:19.741266   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sq9vk" "namespace"="test-mhc-8bt4l" 
I0807 03:04:19.741806   10671 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-8bt4l/test-mhc-sq9vk/test-mhc-machine-zpqd2/"
node created: test-mhc-node-zrj8w
E0807 03:04:19.771730   10671 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-zrj8w"
E0807 03:04:19.772000   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zrj8w, got []"  "node"="test-mhc-node-zrj8w"
I0807 03:04:19.773901   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sq9vk" "namespace"="test-mhc-8bt4l" 
I0807 03:04:19.774502   10671 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-8bt4l/test-mhc-sq9vk/test-mhc-machine-zpqd2/"
I0807 03:04:19.785226   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sq9vk" "namespace"="test-mhc-8bt4l" 
I0807 03:04:19.828871   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sq9vk" "namespace"="test-mhc-8bt4l" 
I0807 03:04:19.834178   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sq9vk" "namespace"="test-mhc-8bt4l" 
Cleaning up nodes, machines and infra machines.
I0807 03:04:19.843414   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sq9vk" "namespace"="test-mhc-8bt4l" 
I0807 03:04:19.843960   10671 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-8bt4l/test-mhc-sq9vk/test-mhc-machine-ztbcr/"
I0807 03:04:19.871308   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sq9vk" "namespace"="test-mhc-8bt4l" 
I0807 03:04:19.871903   10671 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-8bt4l/test-mhc-sq9vk/test-mhc-machine-zpqd2/"
E0807 03:04:19.892995   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"test-mhc-machine-ztbcr\" in namespace \"test-mhc-8bt4l\": cannot find node with matching ProviderID" "controller"="machine" "name"="test-mhc-machine-ztbcr" "namespace"="test-mhc-8bt4l"
E0807 03:04:19.903455   10671 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-8bt4l/test-cluster-jqpfq"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
inframachine created: test-mhc-machine-infra-99h52
machine created: test-mhc-machine-56skj
E0807 03:04:20.107333   10671 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-fnw7n/machine-reconcile-gkkbb"
I0807 03:04:20.120606   10671 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-8bt4l/test-mhc-sq9vk/test-mhc-machine-ztbcr/"
E0807 03:04:20.146628   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-sq9vk\" not found" "controller"="machinehealthcheck" "name"="test-mhc-sq9vk" "namespace"="test-mhc-8bt4l"
E0807 03:04:20.894316   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jqpfq\" for machine \"test-mhc-machine-zpqd2\" in namespace \"test-mhc-8bt4l\": Cluster.cluster.x-k8s.io \"test-cluster-jqpfq\" not found" "controller"="machine" "name"="test-mhc-machine-zpqd2" "namespace"="test-mhc-8bt4l"
I0807 03:04:21.147778   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:21.179949   10671 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0807 03:04:21.219898   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-sq9vk" "namespace"="test-mhc-8bt4l" 
I0807 03:04:21.220007   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:21.221330   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:21.222760   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
... skipping 235 lines ...
I0807 03:04:21.877203   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:21.879213   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:21.882464   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:21.884555   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:21.886551   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:21.890072   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
E0807 03:04:21.899115   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jqpfq\" for machine \"test-mhc-machine-ztbcr\" in namespace \"test-mhc-8bt4l\": Cluster.cluster.x-k8s.io \"test-cluster-jqpfq\" not found" "controller"="machine" "name"="test-mhc-machine-ztbcr" "namespace"="test-mhc-8bt4l"
I0807 03:04:21.900173   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:21.902080   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:21.904039   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:21.905852   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:21.907719   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:21.909549   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
... skipping 315 lines ...
I0807 03:04:22.919051   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:22.922177   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:22.922962   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:22.924161   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:22.926287   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:22.929418   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
E0807 03:04:22.930000   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jqpfq\" for machine \"test-mhc-machine-zpqd2\" in namespace \"test-mhc-8bt4l\": Cluster.cluster.x-k8s.io \"test-cluster-jqpfq\" not found" "controller"="machine" "name"="test-mhc-machine-zpqd2" "namespace"="test-mhc-8bt4l"
I0807 03:04:22.930094   10671 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-wdpvh/test-mhc-kj52f/test-mhc-machine-56skj/"
I0807 03:04:22.946794   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:22.947313   10671 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-wdpvh/test-mhc-kj52f/test-mhc-machine-56skj/"
E0807 03:04:23.024138   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-prxsl, got []"  "node"="test-mhc-node-prxsl"
node created: test-mhc-node-prxsl
I0807 03:04:23.039233   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
inframachine created: test-mhc-machine-infra-cc7fr
machine created: test-mhc-machine-lkkxz
I0807 03:04:23.074711   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:23.093312   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
... skipping 218 lines ...
I0807 03:04:23.914103   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:23.916738   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:23.920278   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:23.924403   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:23.927345   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:23.931659   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
E0807 03:04:23.933828   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jqpfq\" for machine \"test-mhc-machine-ztbcr\" in namespace \"test-mhc-8bt4l\": Cluster.cluster.x-k8s.io \"test-cluster-jqpfq\" not found" "controller"="machine" "name"="test-mhc-machine-ztbcr" "namespace"="test-mhc-8bt4l"
I0807 03:04:23.935805   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:23.941685   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:23.950821   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:23.954273   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:23.958266   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:23.960970   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
... skipping 314 lines ...
I0807 03:04:24.978067   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:24.980350   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:24.986263   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:24.988999   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:24.992029   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:24.993449   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
E0807 03:04:24.994344   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jqpfq\" for machine \"test-mhc-machine-zpqd2\" in namespace \"test-mhc-8bt4l\": Cluster.cluster.x-k8s.io \"test-cluster-jqpfq\" not found" "controller"="machine" "name"="test-mhc-machine-zpqd2" "namespace"="test-mhc-8bt4l"
I0807 03:04:24.995184   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:24.996696   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:24.998227   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:24.999580   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:25.001698   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:25.004849   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
... skipping 235 lines ...
I0807 03:04:25.998183   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:26.001373   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:26.011855   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:26.014846   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:26.018236   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:26.021247   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:26.021656   10671 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-wdpvh/test-mhc-kj52f/test-mhc-machine-lkkxz/"
E0807 03:04:26.028515   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jqpfq\" for machine \"test-mhc-machine-ztbcr\" in namespace \"test-mhc-8bt4l\": Cluster.cluster.x-k8s.io \"test-cluster-jqpfq\" not found" "controller"="machine" "name"="test-mhc-machine-ztbcr" "namespace"="test-mhc-8bt4l"
I0807 03:04:26.036748   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:26.037421   10671 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-wdpvh/test-mhc-kj52f/test-mhc-machine-lkkxz/"
E0807 03:04:26.117645   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zkd52, got []"  "node"="test-mhc-node-zkd52"
node created: test-mhc-node-zkd52
I0807 03:04:26.129357   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
inframachine created: test-mhc-machine-infra-wjxqh
I0807 03:04:26.153275   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
machine created: test-mhc-machine-mdtnk
I0807 03:04:26.162142   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
... skipping 164 lines ...
I0807 03:04:27.018978   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:27.023317   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:27.026408   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:27.029783   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:27.034062   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:27.038712   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
E0807 03:04:27.048910   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jqpfq\" for machine \"test-mhc-machine-zpqd2\" in namespace \"test-mhc-8bt4l\": Cluster.cluster.x-k8s.io \"test-cluster-jqpfq\" not found" "controller"="machine" "name"="test-mhc-machine-zpqd2" "namespace"="test-mhc-8bt4l"
I0807 03:04:27.051772   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:27.060587   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:27.063350   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:27.065556   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:27.067507   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:27.069748   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
... skipping 218 lines ...
I0807 03:04:28.077424   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:28.082076   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:28.084298   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:28.087035   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:28.092535   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:28.097189   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
E0807 03:04:28.117083   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jqpfq\" for machine \"test-mhc-machine-ztbcr\" in namespace \"test-mhc-8bt4l\": Cluster.cluster.x-k8s.io \"test-cluster-jqpfq\" not found" "controller"="machine" "name"="test-mhc-machine-ztbcr" "namespace"="test-mhc-8bt4l"
I0807 03:04:28.123454   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:28.125386   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:28.127817   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:28.130101   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:28.132630   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:28.134932   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
... skipping 203 lines ...
I0807 03:04:29.124653   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:29.129635   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:29.132883   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:29.136612   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:29.138585   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:29.146285   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:29.147000   10671 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-wdpvh/test-mhc-kj52f/test-mhc-machine-mdtnk/"
E0807 03:04:29.174480   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jqpfq\" for machine \"test-mhc-machine-zpqd2\" in namespace \"test-mhc-8bt4l\": Cluster.cluster.x-k8s.io \"test-cluster-jqpfq\" not found" "controller"="machine" "name"="test-mhc-machine-zpqd2" "namespace"="test-mhc-8bt4l"
I0807 03:04:29.181646   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:29.189396   10671 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-wdpvh/test-mhc-kj52f/test-mhc-machine-mdtnk/"
E0807 03:04:29.194299   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-twv2s, got []"  "node"="test-mhc-node-twv2s"
node created: test-mhc-node-twv2s
I0807 03:04:29.255237   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:29.255904   10671 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-wdpvh/test-mhc-kj52f/test-mhc-machine-mdtnk/test-mhc-node-twv2s"
Cleaning up nodes, machines and infra machines.
I0807 03:04:29.274042   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kj52f" "namespace"="test-mhc-wdpvh" 
I0807 03:04:29.274966   10671 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-wdpvh/test-mhc-kj52f/test-mhc-machine-mdtnk/"
Cleaning up nodes, machines and infra machines.
I0807 03:04:29.355870   10671 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-mhbrd" "namespace"="test-mhc-wdpvh" "count"=2
I0807 03:04:29.355990   10671 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-mhbrd" "namespace"="test-mhc-wdpvh" "descendants"="Worker machines: test-mhc-machine-lkkxz,test-mhc-machine-mdtnk,test-mhc-machine-56skj" "indirect descendants count"=1
I0807 03:04:29.365751   10671 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-mhbrd" "namespace"="test-mhc-wdpvh" "count"=2
I0807 03:04:29.365839   10671 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-mhbrd" "namespace"="test-mhc-wdpvh" "descendants"="Worker machines: test-mhc-machine-56skj,test-mhc-machine-lkkxz,test-mhc-machine-mdtnk" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
... skipping 7 lines ...
I0807 03:04:29.542409   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:29.562591   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:29.644120   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:29.805378   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:30.126675   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:30.175286   10671 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-mhbrd" "machine"="test-mhc-machine-lkkxz" "namespace"="test-mhc-wdpvh" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-zkd52"}
E0807 03:04:30.256054   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-lkkxz\" not found" "controller"="machine" "name"="test-mhc-machine-lkkxz" "namespace"="test-mhc-wdpvh"
I0807 03:04:30.768009   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
E0807 03:04:31.256606   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jqpfq\" for machine \"test-mhc-machine-ztbcr\" in namespace \"test-mhc-8bt4l\": Cluster.cluster.x-k8s.io \"test-cluster-jqpfq\" not found" "controller"="machine" "name"="test-mhc-machine-ztbcr" "namespace"="test-mhc-8bt4l"
I0807 03:04:32.049571   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:32.257468   10671 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-mhbrd" "machine"="test-mhc-machine-mdtnk" "namespace"="test-mhc-wdpvh" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-twv2s"}
E0807 03:04:32.358876   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-mdtnk\" not found" "controller"="machine" "name"="test-mhc-machine-mdtnk" "namespace"="test-mhc-wdpvh"
I0807 03:04:33.359516   10671 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-mhbrd" "machine"="test-mhc-machine-56skj" "namespace"="test-mhc-wdpvh" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-prxsl"}
E0807 03:04:33.429058   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-56skj\" not found" "controller"="machine" "name"="test-mhc-machine-56skj" "namespace"="test-mhc-wdpvh"
E0807 03:04:34.408313   10671 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-wdpvh/test-cluster-mhbrd"
E0807 03:04:34.431762   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jqpfq\" for machine \"test-mhc-machine-zpqd2\" in namespace \"test-mhc-8bt4l\": Cluster.cluster.x-k8s.io \"test-cluster-jqpfq\" not found" "controller"="machine" "name"="test-mhc-machine-zpqd2" "namespace"="test-mhc-8bt4l"
I0807 03:04:34.614465   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:35.443062   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
E0807 03:04:35.449986   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jqpfq\" for machine \"test-mhc-machine-ztbcr\" in namespace \"test-mhc-8bt4l\": Cluster.cluster.x-k8s.io \"test-cluster-jqpfq\" not found" "controller"="machine" "name"="test-mhc-machine-ztbcr" "namespace"="test-mhc-8bt4l"
I0807 03:04:35.450554   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
node created: test-mhc-node-mrkbd
E0807 03:04:35.477899   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-mrkbd, got []"  "node"="test-mhc-node-mrkbd"
inframachine created: test-mhc-machine-infra-wlrmj
I0807 03:04:35.519643   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
machine created: test-mhc-machine-2ttx7
I0807 03:04:35.572435   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:35.602469   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:35.634224   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:35.644879   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:35.686491   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:35.767832   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:35.929798   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:36.252036   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
E0807 03:04:36.450412   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jqpfq\" for machine \"test-mhc-machine-zpqd2\" in namespace \"test-mhc-8bt4l\": Cluster.cluster.x-k8s.io \"test-cluster-jqpfq\" not found" "controller"="machine" "name"="test-mhc-machine-zpqd2" "namespace"="test-mhc-8bt4l"
I0807 03:04:36.893990   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:37.474427   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:37.485758   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:37.518471   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:37.545779   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:37.564412   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
E0807 03:04:37.589683   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jqpfq\" for machine \"test-mhc-machine-ztbcr\" in namespace \"test-mhc-8bt4l\": Cluster.cluster.x-k8s.io \"test-cluster-jqpfq\" not found" "controller"="machine" "name"="test-mhc-machine-ztbcr" "namespace"="test-mhc-8bt4l"
I0807 03:04:37.595758   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:37.656225   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
node created: test-mhc-node-7bs25
E0807 03:04:37.667537   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-7bs25, got []"  "node"="test-mhc-node-7bs25"
I0807 03:04:37.679597   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
inframachine created: test-mhc-machine-infra-xllk4
I0807 03:04:37.697686   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:37.704101   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
machine created: test-mhc-machine-r2rls
I0807 03:04:37.737384   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:38.176972   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
E0807 03:04:38.590189   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jqpfq\" for machine \"test-mhc-machine-zpqd2\" in namespace \"test-mhc-8bt4l\": Cluster.cluster.x-k8s.io \"test-cluster-jqpfq\" not found" "controller"="machine" "name"="test-mhc-machine-zpqd2" "namespace"="test-mhc-8bt4l"
I0807 03:04:39.608210   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:39.661003   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:39.667824   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:39.677047   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:39.698006   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:39.715701   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:39.735065   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
E0807 03:04:39.746015   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jqpfq\" for machine \"test-mhc-machine-ztbcr\" in namespace \"test-mhc-8bt4l\": Cluster.cluster.x-k8s.io \"test-cluster-jqpfq\" not found" "controller"="machine" "name"="test-mhc-machine-ztbcr" "namespace"="test-mhc-8bt4l"
I0807 03:04:39.746660   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:39.792286   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
E0807 03:04:39.828742   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-jj2rl, got []"  "node"="test-mhc-node-jj2rl"
node created: test-mhc-node-jj2rl
Cleaning up nodes, machines and infra machines.
I0807 03:04:39.864719   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:39.910796   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
Cleaning up nodes, machines and infra machines.
I0807 03:04:40.008716   10671 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-c2j8c" "namespace"="test-mhc-st65c" "count"=2
... skipping 5 lines ...
machine created: test-mhc-machine-z4z74
I0807 03:04:40.207702   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g6fxf" "namespace"="test-mhc-94knj" 
I0807 03:04:40.235146   10671 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0807 03:04:40.385006   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-mb4vb" "namespace"="test-mhc-st65c" 
I0807 03:04:40.385089   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g6fxf" "namespace"="test-mhc-94knj" 
I0807 03:04:40.746785   10671 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-c2j8c" "machine"="test-mhc-machine-lnnjv" "namespace"="test-mhc-st65c" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-mrkbd"}
E0807 03:04:40.822448   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-lnnjv\" not found" "controller"="machine" "name"="test-mhc-machine-lnnjv" "namespace"="test-mhc-st65c"
I0807 03:04:41.823456   10671 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-c2j8c" "machine"="test-mhc-machine-2ttx7" "namespace"="test-mhc-st65c" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-7bs25"}
E0807 03:04:41.890055   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-2ttx7\" not found" "controller"="machine" "name"="test-mhc-machine-2ttx7" "namespace"="test-mhc-st65c"
I0807 03:04:42.890673   10671 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-c2j8c" "machine"="test-mhc-machine-r2rls" "namespace"="test-mhc-st65c" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-jj2rl"}
E0807 03:04:42.964969   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-r2rls\" not found" "controller"="machine" "name"="test-mhc-machine-r2rls" "namespace"="test-mhc-st65c"
E0807 03:04:43.965426   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jqpfq\" for machine \"test-mhc-machine-zpqd2\" in namespace \"test-mhc-8bt4l\": Cluster.cluster.x-k8s.io \"test-cluster-jqpfq\" not found" "controller"="machine" "name"="test-mhc-machine-zpqd2" "namespace"="test-mhc-8bt4l"
I0807 03:04:44.975975   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g6fxf" "namespace"="test-mhc-94knj" 
E0807 03:04:44.983872   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jqpfq\" for machine \"test-mhc-machine-ztbcr\" in namespace \"test-mhc-8bt4l\": Cluster.cluster.x-k8s.io \"test-cluster-jqpfq\" not found" "controller"="machine" "name"="test-mhc-machine-ztbcr" "namespace"="test-mhc-8bt4l"
I0807 03:04:44.984442   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g6fxf" "namespace"="test-mhc-94knj" 
E0807 03:04:45.016309   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-nkrjw, got []"  "node"="test-mhc-node-nkrjw"
E0807 03:04:45.016643   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-nkrjw, got []"  "node"="test-mhc-node-nkrjw"
node created: test-mhc-node-nkrjw
I0807 03:04:45.024672   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g6fxf" "namespace"="test-mhc-94knj" 
inframachine created: test-mhc-machine-infra-d2wtx
I0807 03:04:45.050960   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g6fxf" "namespace"="test-mhc-94knj" 
machine created: test-mhc-machine-cljgc
E0807 03:04:45.057857   10671 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-st65c/test-cluster-c2j8c"
I0807 03:04:45.058929   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g6fxf" "namespace"="test-mhc-94knj" 
I0807 03:04:45.074965   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g6fxf" "namespace"="test-mhc-94knj" 
I0807 03:04:46.016101   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g6fxf" "namespace"="test-mhc-94knj" 
I0807 03:04:46.026119   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g6fxf" "namespace"="test-mhc-94knj" 
I0807 03:04:46.048745   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g6fxf" "namespace"="test-mhc-94knj" 
I0807 03:04:46.062446   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g6fxf" "namespace"="test-mhc-94knj" 
I0807 03:04:46.075432   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g6fxf" "namespace"="test-mhc-94knj" 
I0807 03:04:46.090544   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g6fxf" "namespace"="test-mhc-94knj" 
I0807 03:04:46.111271   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g6fxf" "namespace"="test-mhc-94knj" 
I0807 03:04:46.141191   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g6fxf" "namespace"="test-mhc-94knj" 
I0807 03:04:46.155742   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g6fxf" "namespace"="test-mhc-94knj" 
E0807 03:04:46.162856   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-klsr8, got []"  "node"="test-mhc-node-klsr8"
node created: test-mhc-node-klsr8
I0807 03:04:46.169397   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g6fxf" "namespace"="test-mhc-94knj" 
I0807 03:04:46.178264   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g6fxf" "namespace"="test-mhc-94knj" 
inframachine created: test-mhc-machine-infra-2pvhm
machine created: test-mhc-machine-f747n
I0807 03:04:46.224052   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g6fxf" "namespace"="test-mhc-94knj" 
... skipping 3 lines ...
I0807 03:04:46.276004   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g6fxf" "namespace"="test-mhc-94knj" 
I0807 03:04:46.298869   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g6fxf" "namespace"="test-mhc-94knj" 
Cleaning up nodes, machines and infra machines.
I0807 03:04:46.330206   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g6fxf" "namespace"="test-mhc-94knj" 
Cleaning up nodes, machines and infra machines.
I0807 03:04:46.361393   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g6fxf" "namespace"="test-mhc-94knj" 
I0807 03:04:46.362241   10671 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-94knj/test-mhc-g6fxf/test-mhc-machine-z4z74/"
I0807 03:04:46.382520   10671 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-lz9wk" "machine"="test-mhc-machine-z4z74" "namespace"="test-mhc-94knj" "cause"="no control plane members" "node"={"name":"test-mhc-node-nkrjw"}
I0807 03:04:46.392491   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g6fxf" "namespace"="test-mhc-94knj" 
I0807 03:04:46.393404   10671 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-94knj/test-mhc-g6fxf/test-mhc-machine-z4z74/"
I0807 03:04:46.394869   10671 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-94knj/test-mhc-g6fxf/test-mhc-machine-cljgc/"
I0807 03:04:46.444891   10671 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-lz9wk" "namespace"="test-mhc-94knj" "count"=3
I0807 03:04:46.445248   10671 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-lz9wk" "namespace"="test-mhc-94knj" "descendants"="Worker machines: test-mhc-machine-z4z74,test-mhc-machine-cljgc,test-mhc-machine-f747n" "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
I0807 03:04:46.453572   10671 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-lz9wk" "namespace"="test-mhc-94knj" "count"=3
I0807 03:04:46.453646   10671 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-lz9wk" "namespace"="test-mhc-94knj" "descendants"="Worker machines: test-mhc-machine-z4z74,test-mhc-machine-cljgc,test-mhc-machine-f747n" "indirect descendants count"=0
E0807 03:04:46.502664   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-z4z74\" not found" "controller"="machine" "name"="test-mhc-machine-z4z74" "namespace"="test-mhc-94knj"
inframachine created: test-mhc-machine-infra-fbx8c
machine created: test-mhc-machine-f5phj
E0807 03:04:46.543204   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-g6fxf\" not found" "controller"="machinehealthcheck" "name"="test-mhc-g6fxf" "namespace"="test-mhc-94knj"
I0807 03:04:47.504147   10671 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-lz9wk" "machine"="test-mhc-machine-f747n" "namespace"="test-mhc-94knj" "cause"="cluster is being deleted" "node"=null
I0807 03:04:47.543613   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:47.581199   10671 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0807 03:04:47.623838   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g6fxf" "namespace"="test-mhc-94knj" 
I0807 03:04:47.623925   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:47.625339   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:47.627728   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:47.629642   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:47.632508   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:47.634572   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:47.636460   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:47.638409   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
E0807 03:04:47.659215   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-f747n\" not found" "controller"="machine" "name"="test-mhc-machine-f747n" "namespace"="test-mhc-94knj"
I0807 03:04:47.659856   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:47.665286   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:47.674990   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:47.677072   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:47.682090   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:47.684212   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
... skipping 386 lines ...
I0807 03:04:48.716643   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:48.718886   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:48.720880   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:48.723477   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:48.725507   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:48.728381   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
E0807 03:04:48.737788   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-cljgc\" not found" "controller"="machine" "name"="test-mhc-machine-cljgc" "namespace"="test-mhc-94knj"
I0807 03:04:48.740698   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:48.742788   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:48.744972   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:48.747053   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:48.748923   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:48.750773   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
... skipping 382 lines ...
I0807 03:04:49.727453   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:49.729842   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:49.732202   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:49.734162   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:49.737091   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:49.739072   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
E0807 03:04:49.739730   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jqpfq\" for machine \"test-mhc-machine-zpqd2\" in namespace \"test-mhc-8bt4l\": Cluster.cluster.x-k8s.io \"test-cluster-jqpfq\" not found" "controller"="machine" "name"="test-mhc-machine-zpqd2" "namespace"="test-mhc-8bt4l"
I0807 03:04:49.741036   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:49.743558   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:49.745677   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:49.747732   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:49.749845   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:49.752609   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
... skipping 329 lines ...
I0807 03:04:50.744371   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:50.746204   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:50.749186   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:50.751600   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:50.753630   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:50.756097   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
E0807 03:04:50.757623   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jqpfq\" for machine \"test-mhc-machine-ztbcr\" in namespace \"test-mhc-8bt4l\": Cluster.cluster.x-k8s.io \"test-cluster-jqpfq\" not found" "controller"="machine" "name"="test-mhc-machine-ztbcr" "namespace"="test-mhc-8bt4l"
I0807 03:04:50.757995   10671 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-k59pc/test-mhc-bb98q/test-mhc-machine-f5phj/"
I0807 03:04:50.771736   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:50.772355   10671 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-k59pc/test-mhc-bb98q/test-mhc-machine-f5phj/"
E0807 03:04:50.795233   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-znpvq, got []"  "node"="test-mhc-node-znpvq"
E0807 03:04:50.795429   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-znpvq, got []"  "node"="test-mhc-node-znpvq"
node created: test-mhc-node-znpvq
I0807 03:04:50.806086   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:50.836257   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:50.849166   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:50.850405   10671 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-k59pc/test-mhc-bb98q/test-mhc-machine-f5phj/test-mhc-node-znpvq"
I0807 03:04:50.875103   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:50.875583   10671 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-k59pc/test-mhc-bb98q/test-mhc-machine-f5phj/test-mhc-node-znpvq"
Cleaning up nodes, machines and infra machines.
I0807 03:04:50.893869   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:50.894301   10671 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-k59pc/test-mhc-bb98q/test-mhc-machine-f5phj/"
I0807 03:04:50.912411   10671 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-6z59s" "namespace"="test-mhc-k59pc" "descendants"="Worker machines: test-mhc-machine-f5phj" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0807 03:04:50.920361   10671 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-6z59s" "namespace"="test-mhc-k59pc" "descendants"="Worker machines: test-mhc-machine-f5phj" "indirect descendants count"=1
I0807 03:04:51.042306   10671 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-crv66" "namespace"="test-mhc-c5cm2" "creating"=1 "need"=1
I0807 03:04:51.042386   10671 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-crv66" "namespace"="test-mhc-c5cm2" 
I0807 03:04:51.057466   10671 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-crv66-6tl4x\"" "machineset"="mhc-ms-crv66" "namespace"="test-mhc-c5cm2" 
I0807 03:04:51.101068   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bb98q" "namespace"="test-mhc-k59pc" 
I0807 03:04:51.127189   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7csrs" "namespace"="test-mhc-c5cm2" 
I0807 03:04:51.169874   10671 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0807 03:04:51.172377   10671 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-crv66" "namespace"="test-mhc-c5cm2" 
I0807 03:04:51.249289   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7csrs" "namespace"="test-mhc-c5cm2" 
I0807 03:04:51.256596   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7csrs" "namespace"="test-mhc-c5cm2" 
E0807 03:04:51.476178   10671 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-94knj/test-cluster-lz9wk"
I0807 03:04:51.758331   10671 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-6z59s" "machine"="test-mhc-machine-f5phj" "namespace"="test-mhc-k59pc" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-znpvq"}
E0807 03:04:51.822189   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-f5phj\" not found" "controller"="machine" "name"="test-mhc-machine-f5phj" "namespace"="test-mhc-k59pc"
I0807 03:04:52.249517   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7csrs" "namespace"="test-mhc-c5cm2" 
I0807 03:04:52.835332   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7csrs" "namespace"="test-mhc-c5cm2" 
I0807 03:04:52.836629   10671 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-crv66" "namespace"="test-mhc-c5cm2" 
I0807 03:04:52.844894   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7csrs" "namespace"="test-mhc-c5cm2" 
I0807 03:04:52.846068   10671 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-crv66" "namespace"="test-mhc-c5cm2" 
I0807 03:04:52.878651   10671 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-crv66-6tl4x" "namespace"="test-mhc-c5cm2" 
... skipping 4 lines ...
I0807 03:04:52.896641   10671 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-crv66" "namespace"="test-mhc-c5cm2" 
I0807 03:04:52.901224   10671 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-crv66-6tl4x" "namespace"="test-mhc-c5cm2" 
I0807 03:04:52.901287   10671 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-crv66-6tl4x" "namespace"="test-mhc-c5cm2" 
I0807 03:04:52.924979   10671 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-crv66-6tl4x" "namespace"="test-mhc-c5cm2" 
I0807 03:04:52.925061   10671 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-crv66-6tl4x" "namespace"="test-mhc-c5cm2" 
I0807 03:04:53.258124   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7csrs" "namespace"="test-mhc-c5cm2" 
I0807 03:04:53.258708   10671 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-c5cm2/test-mhc-7csrs/mhc-ms-crv66-6tl4x/"
I0807 03:04:53.268786   10671 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-crv66" "namespace"="test-mhc-c5cm2" 
I0807 03:04:53.274034   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7csrs" "namespace"="test-mhc-c5cm2" 
I0807 03:04:53.274408   10671 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-c5cm2/test-mhc-7csrs/mhc-ms-crv66-6tl4x/"
I0807 03:04:53.276348   10671 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-crv66-6tl4x" "namespace"="test-mhc-c5cm2" 
I0807 03:04:53.276395   10671 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-crv66-6tl4x" "namespace"="test-mhc-c5cm2" 
I0807 03:04:53.297206   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7csrs" "namespace"="test-mhc-c5cm2" 
I0807 03:04:53.297661   10671 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-c5cm2/test-mhc-7csrs/mhc-ms-crv66-6tl4x/"
I0807 03:04:53.310607   10671 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-crv66" "namespace"="test-mhc-c5cm2" "machine"="mhc-ms-crv66-6tl4x"
I0807 03:04:53.313232   10671 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-5vnk9" "namespace"="test-mhc-c5cm2" "count"=1
I0807 03:04:53.313304   10671 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-5vnk9" "namespace"="test-mhc-c5cm2" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-crv66"
I0807 03:04:53.321698   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7csrs" "namespace"="test-mhc-c5cm2" 
I0807 03:04:53.322153   10671 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-c5cm2/test-mhc-7csrs/mhc-ms-crv66-6tl4x/"
I0807 03:04:53.326452   10671 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-crv66-6tl4x" "namespace"="test-mhc-c5cm2" 
I0807 03:04:53.326595   10671 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-crv66-6tl4x" "namespace"="test-mhc-c5cm2" 
I0807 03:04:53.329442   10671 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-5vnk9" "namespace"="test-mhc-c5cm2" "descendants"="Machine sets: mhc-ms-crv66;Worker machines: mhc-ms-crv66-6tl4x" "indirect descendants count"=1
I0807 03:04:53.331039   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7csrs" "namespace"="test-mhc-c5cm2" 
I0807 03:04:53.335831   10671 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-5vnk9" "machine"="mhc-ms-crv66-6tl4x" "namespace"="test-mhc-c5cm2" "cause"="cluster is being deleted" "node"=null
E0807 03:04:53.343938   10671 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-crv66\" not found" "machineset"="mhc-ms-crv66" "namespace"="test-mhc-c5cm2" 
E0807 03:04:53.344048   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to patch MachineSet's Status: machinesets.cluster.x-k8s.io \"mhc-ms-crv66\" not found" "controller"="machineset" "name"="mhc-ms-crv66" "namespace"="test-mhc-c5cm2"
=== 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
I0807 03:04:53.356174   10671 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-5vnk9" "namespace"="test-mhc-c5cm2" "descendants"="Worker machines: mhc-ms-crv66-6tl4x" "indirect descendants count"=1
I0807 03:04:53.419723   10671 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-5vnk9" "machine"="mhc-ms-crv66-6tl4x" "namespace"="test-mhc-c5cm2" "cause"="cluster is being deleted" "node"=null
E0807 03:04:53.470774   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-crv66-6tl4x\" not found" "controller"="machine" "name"="mhc-ms-crv66-6tl4x" "namespace"="test-mhc-c5cm2"
I0807 03:04:53.513346   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnqw" "namespace"="test-mhc-j6vhh" 
inframachine created: test-mhc-machine-infra-h59s8
I0807 03:04:53.542659   10671 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-fflv9
I0807 03:04:53.670099   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnqw" "namespace"="test-mhc-j6vhh" 
I0807 03:04:53.670953   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnqw" "namespace"="test-mhc-j6vhh" 
... skipping 329 lines ...
I0807 03:04:54.479374   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnqw" "namespace"="test-mhc-j6vhh" 
I0807 03:04:54.480709   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnqw" "namespace"="test-mhc-j6vhh" 
I0807 03:04:54.483661   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnqw" "namespace"="test-mhc-j6vhh" 
I0807 03:04:54.485754   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnqw" "namespace"="test-mhc-j6vhh" 
I0807 03:04:54.488099   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnqw" "namespace"="test-mhc-j6vhh" 
I0807 03:04:54.490036   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnqw" "namespace"="test-mhc-j6vhh" 
E0807 03:04:54.556304   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-g2sl6, got []"  "node"="test-mhc-node-g2sl6"
E0807 03:04:54.556304   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-g2sl6, got []"  "node"="test-mhc-node-g2sl6"
E0807 03:04:54.556327   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-g2sl6, got []"  "node"="test-mhc-node-g2sl6"
node created: test-mhc-node-g2sl6
I0807 03:04:54.556951   10671 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-fflv9" "namespace"="test-mhc-j6vhh" "noderef"="test-mhc-node-g2sl6"
I0807 03:04:54.561010   10671 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-fflv9" "target"="test-mhc-j6vhh/test-mhc-nvnqw/test-mhc-machine-fflv9/"
E0807 03:04:54.586248   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-g2sl6, got []"  "node"="test-mhc-node-g2sl6"
E0807 03:04:54.586311   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-g2sl6, got []"  "node"="test-mhc-node-g2sl6"
E0807 03:04:54.586554   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-g2sl6, got []"  "node"="test-mhc-node-g2sl6"
E0807 03:04:54.586592   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-g2sl6, got []"  "node"="test-mhc-node-g2sl6"
E0807 03:04:54.586792   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-g2sl6, got []"  "node"="test-mhc-node-g2sl6"
E0807 03:04:54.586823   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-g2sl6, got []"  "node"="test-mhc-node-g2sl6"
I0807 03:04:54.613087   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnqw" "namespace"="test-mhc-j6vhh" 
I0807 03:04:54.655172   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnqw" "namespace"="test-mhc-j6vhh" 
I0807 03:04:54.658789   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnqw" "namespace"="test-mhc-j6vhh" 
I0807 03:04:54.668513   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnqw" "namespace"="test-mhc-j6vhh" 
I0807 03:04:54.673168   10671 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-fflv9" "target"="test-mhc-j6vhh/test-mhc-nvnqw/test-mhc-machine-fflv9/test-mhc-node-g2sl6"
I0807 03:04:54.698901   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnqw" "namespace"="test-mhc-j6vhh" 
I0807 03:04:54.702056   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnqw" "namespace"="test-mhc-j6vhh" 
Cleaning up nodes, machines and infra machines.
I0807 03:04:54.716386   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnqw" "namespace"="test-mhc-j6vhh" 
I0807 03:04:54.720856   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnqw" "namespace"="test-mhc-j6vhh" 
I0807 03:04:54.726110   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnqw" "namespace"="test-mhc-j6vhh" 
... skipping 4 lines ...
I0807 03:04:54.745979   10671 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-5lb9l" "namespace"="test-mhc-j6vhh" "descendants"="Worker machines: test-mhc-machine-fflv9" "indirect descendants count"=0
I0807 03:04:54.751984   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnqw" "namespace"="test-mhc-j6vhh" 
I0807 03:04:54.756206   10671 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-5lb9l" "namespace"="test-mhc-j6vhh" "count"=1
I0807 03:04:54.756273   10671 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-5lb9l" "namespace"="test-mhc-j6vhh" "descendants"="Worker machines: test-mhc-machine-fflv9" "indirect descendants count"=0
I0807 03:04:54.769982   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nvnqw" "namespace"="test-mhc-j6vhh" 
=== RUN   TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted
E0807 03:04:54.831466   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-fflv9\" not found" "controller"="machine" "name"="test-mhc-machine-fflv9" "namespace"="test-mhc-j6vhh"
I0807 03:04:54.931433   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
inframachine created: test-mhc-machine-infra-fzqh6
I0807 03:04:54.964925   10671 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-2rtsb
I0807 03:04:55.009904   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:55.019630   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
... skipping 307 lines ...
I0807 03:04:55.820445   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:55.822264   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:55.824416   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:55.826354   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:55.828277   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:55.830060   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
E0807 03:04:55.831867   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jqpfq\" for machine \"test-mhc-machine-zpqd2\" in namespace \"test-mhc-8bt4l\": Cluster.cluster.x-k8s.io \"test-cluster-jqpfq\" not found" "controller"="machine" "name"="test-mhc-machine-zpqd2" "namespace"="test-mhc-8bt4l"
I0807 03:04:55.831935   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:55.833743   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:55.835620   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:55.837411   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:55.839343   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:55.841203   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
... skipping 29 lines ...
I0807 03:04:55.923192   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:55.925037   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:55.926904   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:55.928729   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:55.930858   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:55.932765   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
E0807 03:04:55.934737   10671 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-k59pc/test-cluster-6z59s"
I0807 03:04:55.934798   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:55.936672   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:55.939389   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:55.941474   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:55.943277   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:55.945268   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
... skipping 341 lines ...
I0807 03:04:56.837194   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:56.839012   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:56.841200   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:56.841923   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:56.844458   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:56.846389   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
E0807 03:04:56.847562   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jqpfq\" for machine \"test-mhc-machine-ztbcr\" in namespace \"test-mhc-8bt4l\": Cluster.cluster.x-k8s.io \"test-cluster-jqpfq\" not found" "controller"="machine" "name"="test-mhc-machine-ztbcr" "namespace"="test-mhc-8bt4l"
I0807 03:04:56.847749   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:56.859480   10671 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-2rtsb" "target"="test-mhc-6h675/test-mhc-npdlw/test-mhc-machine-2rtsb/"
I0807 03:04:56.882485   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
E0807 03:04:56.898435   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-drvgp, got []"  "node"="test-mhc-node-drvgp"
E0807 03:04:56.898691   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-drvgp, got []"  "node"="test-mhc-node-drvgp"
E0807 03:04:56.898929   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-drvgp, got []"  "node"="test-mhc-node-drvgp"
node created: test-mhc-node-drvgp
I0807 03:04:56.910248   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:56.953616   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:56.969298   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:56.974969   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:56.992051   10671 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-2rtsb" "target"="test-mhc-6h675/test-mhc-npdlw/test-mhc-machine-2rtsb/test-mhc-node-drvgp"
I0807 03:04:57.018526   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:57.032295   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:57.040278   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:57.079599   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
Cleaning up nodes, machines and infra machines.
I0807 03:04:57.090833   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:57.096574   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
I0807 03:04:57.105490   10671 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-2rtsb" "target"="test-mhc-6h675/test-mhc-npdlw/test-mhc-machine-2rtsb/"
I0807 03:04:57.150603   10671 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-tfq5m" "namespace"="test-mhc-6h675" "descendants"="Worker machines: test-mhc-machine-2rtsb" "indirect descendants count"=1
I0807 03:04:57.156165   10671 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-tfq5m" "namespace"="test-mhc-6h675" "descendants"="Worker machines: test-mhc-machine-2rtsb" "indirect descendants count"=1
--- PASS: TestMachineHealthCheck_Reconcile (39.35s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist (0.07s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value (0.17s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present (0.14s)
... skipping 12 lines ...
    --- SKIP: TestMachineHealthCheck_Reconcile/when_a_machine_is_paused (0.00s)
        machinehealthcheck_controller_test.go:933: skipping until made stable
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created (1.44s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (2.38s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0807 03:04:57.173143   10671 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
E0807 03:04:57.175130   10671 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
E0807 03:04:57.177307   10671 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E0807 03:04:57.177784   10671 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
E0807 03:04:57.178509   10671 machinehealthcheck_controller.go:480]  "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node node1, got [machine1 machine2]"  "node"="node1"
=== RUN   TestNodeToMachineHealthCheck/when_no_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_two_MachineHealthChecks_exist_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node,_but_not_in_the_Machine's_cluster
--- PASS: TestNodeToMachineHealthCheck (0.01s)
    --- PASS: TestNodeToMachineHealthCheck/when_the_object_passed_isn't_a_Node (0.00s)
... skipping 31 lines ...
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_nil (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_not_an_int_or_percentage (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_an_int (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_a_40%_(of_5) (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_a_60%_(of_7) (0.00s)
=== RUN   TestPatchTargets
I0807 03:04:57.188821   10671 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0807 03:04:57.189638   10671 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0807 03:04:57.192860   10671 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.02s)
=== 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
E0807 03:04:57.223559   10671 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
E0807 03:04:57.225461   10671 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: 1659841436
Will run 16 of 16 specs

E0807 03:04:57.280236   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-npdlw\" not found" "controller"="machinehealthcheck" "name"="test-mhc-npdlw" "namespace"="test-mhc-6h675"
I0807 03:04:57.331919   10671 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-zcwb7-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0807 03:04:57.332006   10671 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-zcwb7-6657c7fddb" "namespace"="md-test" 
I0807 03:04:57.366570   10671 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-zcwb7-6657c7fddb-gfx49\"" "machineset"="md-zcwb7-6657c7fddb" "namespace"="md-test" 
I0807 03:04:57.366652   10671 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-zcwb7-6657c7fddb" "namespace"="md-test" 
I0807 03:04:57.385924   10671 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-zcwb7-6657c7fddb-rsqfs\"" "machineset"="md-zcwb7-6657c7fddb" "namespace"="md-test" 
I0807 03:04:57.518456   10671 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-zcwb7-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
... skipping 4 lines ...
I0807 03:04:57.632450   10671 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-zcwb7-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3
I0807 03:04:57.632505   10671 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-zcwb7-6657c7fddb" "namespace"="md-test" 
I0807 03:04:57.651121   10671 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-zcwb7-6657c7fddb-jdtdc\"" "machineset"="md-zcwb7-6657c7fddb" "namespace"="md-test" 
I0807 03:04:57.772163   10671 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-zcwb7-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0807 03:04:57.772220   10671 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-zcwb7-cdfc6fd6c" "namespace"="md-test" 
I0807 03:04:57.786861   10671 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-zcwb7-cdfc6fd6c-6smxf\"" "machineset"="md-zcwb7-cdfc6fd6c" "namespace"="md-test" 
E0807 03:04:57.831702   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-zcwb7-cdfc6fd6c-6smxf-7dclk, got []"  "node"="md-zcwb7-cdfc6fd6c-6smxf-7dclk"
E0807 03:04:57.832053   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-zcwb7-cdfc6fd6c-6smxf-7dclk, got []"  "node"="md-zcwb7-cdfc6fd6c-6smxf-7dclk"
E0807 03:04:57.832139   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-zcwb7-cdfc6fd6c-6smxf-7dclk, got []"  "node"="md-zcwb7-cdfc6fd6c-6smxf-7dclk"
I0807 03:04:57.848141   10671 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-tfq5m" "machine"="test-mhc-machine-2rtsb" "namespace"="test-mhc-6h675" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-drvgp"}
E0807 03:04:57.938930   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-zcwb7-cdfc6fd6c-6smxf-7dclk, got []"  "node"="md-zcwb7-cdfc6fd6c-6smxf-7dclk"
E0807 03:04:57.938994   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-zcwb7-cdfc6fd6c-6smxf-7dclk, got []"  "node"="md-zcwb7-cdfc6fd6c-6smxf-7dclk"
E0807 03:04:57.940864   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-zcwb7-cdfc6fd6c-6smxf-7dclk, got []"  "node"="md-zcwb7-cdfc6fd6c-6smxf-7dclk"
E0807 03:04:57.940925   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-zcwb7-cdfc6fd6c-6smxf-7dclk, got []"  "node"="md-zcwb7-cdfc6fd6c-6smxf-7dclk"
E0807 03:04:57.941133   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-zcwb7-cdfc6fd6c-6smxf-7dclk, got []"  "node"="md-zcwb7-cdfc6fd6c-6smxf-7dclk"
E0807 03:04:57.941162   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-zcwb7-cdfc6fd6c-6smxf-7dclk, got []"  "node"="md-zcwb7-cdfc6fd6c-6smxf-7dclk"
E0807 03:04:57.989648   10671 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-zcwb7-cdfc6fd6c-6smxf-7dclk for machine md-test/md-zcwb7-cdfc6fd6c-6smxf: the cache is not started, can not read objects" "machineset"="md-zcwb7-cdfc6fd6c" "namespace"="md-test" 
E0807 03:04:57.995685   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-2rtsb\" not found" "controller"="machine" "name"="test-mhc-machine-2rtsb" "namespace"="test-mhc-6h675"
I0807 03:04:58.280583   10671 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-npdlw" "namespace"="test-mhc-6h675" 
E0807 03:04:58.376878   10671 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-c5cm2/test-cluster-5vnk9"
I0807 03:04:59.182605   10671 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-zcwb7-6657c7fddb-gfx49" "namespace"="md-test" 
I0807 03:04:59.182667   10671 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-zcwb7-6657c7fddb-gfx49" "namespace"="md-test" 
I0807 03:04:59.215999   10671 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-zcwb7-6657c7fddb-rsqfs" "namespace"="md-test" 
I0807 03:04:59.216057   10671 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-zcwb7-6657c7fddb-rsqfs" "namespace"="md-test" 
I0807 03:04:59.228409   10671 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-zcwb7-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0807 03:04:59.228475   10671 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-zcwb7-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
... skipping 4 lines ...
I0807 03:04:59.329938   10671 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-zcwb7-6657c7fddb-2lvqc" "namespace"="md-test" 
I0807 03:04:59.361715   10671 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-zcwb7-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0807 03:04:59.361777   10671 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-zcwb7-cdfc6fd6c" "namespace"="md-test" 
I0807 03:04:59.384952   10671 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-zcwb7-6657c7fddb-jdtdc" "namespace"="md-test" 
I0807 03:04:59.385017   10671 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-zcwb7-6657c7fddb-jdtdc" "namespace"="md-test" 
I0807 03:04:59.390117   10671 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-zcwb7-cdfc6fd6c-jndwj\"" "machineset"="md-zcwb7-cdfc6fd6c" "namespace"="md-test" 
E0807 03:04:59.453398   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-zcwb7-cdfc6fd6c-jndwj-hbmf6, got []"  "node"="md-zcwb7-cdfc6fd6c-jndwj-hbmf6"
E0807 03:04:59.453529   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-zcwb7-cdfc6fd6c-jndwj-hbmf6, got []"  "node"="md-zcwb7-cdfc6fd6c-jndwj-hbmf6"
E0807 03:04:59.465220   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-zcwb7-cdfc6fd6c-6smxf\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-zcwb7-cdfc6fd6c-6smxf" "namespace"="md-test"
E0807 03:04:59.558165   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-zcwb7-cdfc6fd6c-jndwj-hbmf6, got []"  "node"="md-zcwb7-cdfc6fd6c-jndwj-hbmf6"
E0807 03:04:59.558244   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-zcwb7-cdfc6fd6c-jndwj-hbmf6, got []"  "node"="md-zcwb7-cdfc6fd6c-jndwj-hbmf6"
E0807 03:04:59.558291   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-zcwb7-cdfc6fd6c-jndwj-hbmf6, got []"  "node"="md-zcwb7-cdfc6fd6c-jndwj-hbmf6"
E0807 03:04:59.558341   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-zcwb7-cdfc6fd6c-jndwj-hbmf6, got []"  "node"="md-zcwb7-cdfc6fd6c-jndwj-hbmf6"
I0807 03:04:59.671651   10671 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-zcwb7-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=1
I0807 03:04:59.671729   10671 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-zcwb7-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0807 03:04:59.685812   10671 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-zcwb7-6657c7fddb" "namespace"="md-test" "machine"="md-zcwb7-6657c7fddb-2lvqc"
I0807 03:04:59.842434   10671 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-zcwb7-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=3
I0807 03:04:59.842489   10671 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-zcwb7-cdfc6fd6c" "namespace"="md-test" 
E0807 03:04:59.852497   10671 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-j6vhh/test-cluster-5lb9l"
I0807 03:04:59.869697   10671 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-zcwb7-cdfc6fd6c-m8tqx\"" "machineset"="md-zcwb7-cdfc6fd6c" "namespace"="md-test" 
E0807 03:04:59.986797   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-zcwb7-cdfc6fd6c-m8tqx-q99lb, got []"  "node"="md-zcwb7-cdfc6fd6c-m8tqx-q99lb"
E0807 03:05:00.091367   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-zcwb7-cdfc6fd6c-m8tqx-q99lb, got []"  "node"="md-zcwb7-cdfc6fd6c-m8tqx-q99lb"
E0807 03:05:00.091442   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-zcwb7-cdfc6fd6c-m8tqx-q99lb, got []"  "node"="md-zcwb7-cdfc6fd6c-m8tqx-q99lb"
I0807 03:05:00.175045   10671 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-zcwb7-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=0
I0807 03:05:00.175104   10671 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-zcwb7-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0807 03:05:00.183670   10671 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-zcwb7-6657c7fddb" "namespace"="md-test" "machine"="md-zcwb7-6657c7fddb-jdtdc"
I0807 03:05:00.310011   10671 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-zcwb7-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=1
I0807 03:05:00.310083   10671 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-zcwb7-74d45c49c5" "namespace"="md-test" 
I0807 03:05:00.332604   10671 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-zcwb7-74d45c49c5-fgl25\"" "machineset"="md-zcwb7-74d45c49c5" "namespace"="md-test" 
E0807 03:05:00.411921   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-zcwb7-74d45c49c5-fgl25-7n7b5, got []"  "node"="md-zcwb7-74d45c49c5-fgl25-7n7b5"
E0807 03:05:00.415844   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-zcwb7-74d45c49c5-fgl25-7n7b5, got []"  "node"="md-zcwb7-74d45c49c5-fgl25-7n7b5"
E0807 03:05:00.415899   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-zcwb7-74d45c49c5-fgl25-7n7b5, got []"  "node"="md-zcwb7-74d45c49c5-fgl25-7n7b5"
I0807 03:05:00.468918   10671 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-zcwb7-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2
I0807 03:05:00.468974   10671 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-zcwb7-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0807 03:05:00.478830   10671 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-zcwb7-6657c7fddb-gfx49" "namespace"="md-test" 
I0807 03:05:00.478890   10671 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-zcwb7-6657c7fddb-gfx49" "namespace"="md-test" 
I0807 03:05:00.483377   10671 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-zcwb7-cdfc6fd6c" "namespace"="md-test" "machine"="md-zcwb7-cdfc6fd6c-6smxf"
I0807 03:05:00.486176   10671 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-zcwb7-6657c7fddb-rsqfs" "namespace"="md-test" 
I0807 03:05:00.486236   10671 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-zcwb7-6657c7fddb-rsqfs" "namespace"="md-test" 
I0807 03:05:00.487033   10671 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-zcwb7-6657c7fddb-svvtj" "namespace"="md-test" "cause"="noderef is nil" "node"=null
I0807 03:05:00.536144   10671 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-zcwb7-6657c7fddb-2lvqc" "namespace"="md-test" "cause"="noderef is nil" "node"=null
I0807 03:05:00.627834   10671 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-zcwb7-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=2
I0807 03:05:00.627912   10671 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-zcwb7-74d45c49c5" "namespace"="md-test" 
I0807 03:05:00.641724   10671 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-zcwb7-6657c7fddb-jdtdc" "namespace"="md-test" "cause"="noderef is nil" "node"=null
I0807 03:05:00.652347   10671 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-zcwb7-74d45c49c5-vvjcx\"" "machineset"="md-zcwb7-74d45c49c5" "namespace"="md-test" 
E0807 03:05:00.699313   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-zcwb7-74d45c49c5-vvjcx-wwfhc, got []"  "node"="md-zcwb7-74d45c49c5-vvjcx-wwfhc"
I0807 03:05:00.712956   10671 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-zcwb7-cdfc6fd6c-6smxf" "namespace"="md-test" "cause"="no control plane members" "node"={"name":"md-zcwb7-cdfc6fd6c-6smxf-7dclk"}
E0807 03:05:00.807374   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-zcwb7-74d45c49c5-vvjcx-wwfhc, got []"  "node"="md-zcwb7-74d45c49c5-vvjcx-wwfhc"
E0807 03:05:00.807475   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-zcwb7-74d45c49c5-vvjcx-wwfhc, got []"  "node"="md-zcwb7-74d45c49c5-vvjcx-wwfhc"
I0807 03:05:00.819604   10671 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-zcwb7-6657c7fddb-svvtj" "namespace"="md-test" "cause"="noderef is nil" "node"=null
E0807 03:05:00.880087   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-zcwb7-6657c7fddb-svvtj\" not found" "controller"="machine" "name"="md-zcwb7-6657c7fddb-svvtj" "namespace"="md-test"
I0807 03:05:00.890272   10671 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-zcwb7-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1
I0807 03:05:00.890333   10671 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-zcwb7-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0807 03:05:00.896284   10671 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-zcwb7-cdfc6fd6c" "namespace"="md-test" "machine"="md-zcwb7-cdfc6fd6c-jndwj"
I0807 03:05:01.016616   10671 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-zcwb7-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0807 03:05:01.016683   10671 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-zcwb7-74d45c49c5" "namespace"="md-test" 
I0807 03:05:01.033810   10671 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-zcwb7-74d45c49c5-qpmns\"" "machineset"="md-zcwb7-74d45c49c5" "namespace"="md-test" 
E0807 03:05:01.104279   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-zcwb7-74d45c49c5-qpmns-gdxnl, got []"  "node"="md-zcwb7-74d45c49c5-qpmns-gdxnl"
E0807 03:05:01.209382   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-zcwb7-74d45c49c5-qpmns-gdxnl, got []"  "node"="md-zcwb7-74d45c49c5-qpmns-gdxnl"
E0807 03:05:01.209769   10671 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-zcwb7-74d45c49c5-qpmns-gdxnl, got []"  "node"="md-zcwb7-74d45c49c5-qpmns-gdxnl"
I0807 03:05:01.271808   10671 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-zcwb7-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=0
I0807 03:05:01.271870   10671 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-zcwb7-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
E0807 03:05:01.272192   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinedeployments.cluster.x-k8s.io \"md-zcwb7\" not found" "controller"="machinedeployment" "name"="md-zcwb7" "namespace"="md-test"
I0807 03:05:01.279476   10671 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-zcwb7-74d45c49c5,md-zcwb7-cdfc6fd6c;Worker machines: md-zcwb7-6657c7fddb-2lvqc,md-zcwb7-6657c7fddb-jdtdc,md-zcwb7-74d45c49c5-fgl25,md-zcwb7-6657c7fddb-rsqfs,md-zcwb7-74d45c49c5-qpmns,md-zcwb7-cdfc6fd6c-jndwj,md-zcwb7-cdfc6fd6c-m8tqx,md-zcwb7-74d45c49c5-vvjcx,md-zcwb7-6657c7fddb-gfx49,md-zcwb7-cdfc6fd6c-6smxf" "indirect descendants count"=12
I0807 03:05:01.283167   10671 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-zcwb7-cdfc6fd6c" "namespace"="md-test" "machine"="md-zcwb7-cdfc6fd6c-m8tqx"
I0807 03:05:01.287367   10671 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-zcwb7-74d45c49c5,md-zcwb7-cdfc6fd6c;Worker machines: md-zcwb7-6657c7fddb-rsqfs,md-zcwb7-74d45c49c5-qpmns,md-zcwb7-6657c7fddb-2lvqc,md-zcwb7-6657c7fddb-jdtdc,md-zcwb7-74d45c49c5-fgl25,md-zcwb7-6657c7fddb-gfx49,md-zcwb7-cdfc6fd6c-6smxf,md-zcwb7-cdfc6fd6c-jndwj,md-zcwb7-cdfc6fd6c-m8tqx,md-zcwb7-74d45c49c5-vvjcx" "indirect descendants count"=12
••E0807 03:05:01.450391   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-8mwh8\" not found" "controller"="cluster" "name"="test1-8mwh8" "namespace"="default"
I0807 03:05:01.880763   10671 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-zcwb7-6657c7fddb-2lvqc" "namespace"="md-test" "cause"="cluster is being deleted" "node"=null
E0807 03:05:01.925441   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-zcwb7-6657c7fddb-2lvqc\" not found" "controller"="machine" "name"="md-zcwb7-6657c7fddb-2lvqc" "namespace"="md-test"
E0807 03:05:02.489635   10671 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-6h675/test-cluster-tfq5m"
I0807 03:05:02.626443   10671 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-5cqz7" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
•I0807 03:05:02.756639   10671 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-5cqz7" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0807 03:05:02.766161   10671 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-5cqz7" "namespace"="default"
I0807 03:05:02.926056   10671 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-zcwb7-cdfc6fd6c-jndwj" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-zcwb7-cdfc6fd6c-jndwj-hbmf6"}
I0807 03:05:03.039088   10671 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-zcwb7-6657c7fddb-jdtdc" "namespace"="md-test" "cause"="cluster is being deleted" "node"=null
E0807 03:05:03.082132   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-zcwb7-6657c7fddb-jdtdc\" not found" "controller"="machine" "name"="md-zcwb7-6657c7fddb-jdtdc" "namespace"="md-test"
•E0807 03:05:03.792562   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5cqz7: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5cqz7" "namespace"="default"
I0807 03:05:04.082860   10671 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-zcwb7-cdfc6fd6c-6smxf" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-zcwb7-cdfc6fd6c-6smxf-7dclk"}
E0807 03:05:04.131768   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-zcwb7-cdfc6fd6c-6smxf\" not found" "controller"="machine" "name"="md-zcwb7-cdfc6fd6c-6smxf" "namespace"="md-test"
E0807 03:05:04.814153   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-7xc52\" not found" "controller"="cluster" "name"="test3-7xc52" "namespace"="default"
I0807 03:05:05.132762   10671 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-zcwb7-cdfc6fd6c-m8tqx" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-zcwb7-cdfc6fd6c-m8tqx-q99lb"}
E0807 03:05:05.245598   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-zcwb7-74d45c49c5-fgl25\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-zcwb7-74d45c49c5-fgl25" "namespace"="md-test"
E0807 03:05:05.815002   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5cqz7: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5cqz7" "namespace"="default"
I0807 03:05:06.275094   10671 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-zcwb7-6657c7fddb-gfx49" "namespace"="md-test" 
I0807 03:05:06.275151   10671 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-zcwb7-6657c7fddb-gfx49" "namespace"="md-test" 
I0807 03:05:06.289587   10671 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-zcwb7-6657c7fddb-rsqfs" "namespace"="md-test" 
I0807 03:05:06.289641   10671 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-zcwb7-6657c7fddb-rsqfs" "namespace"="md-test" 
I0807 03:05:06.290450   10671 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-zcwb7-cdfc6fd6c-jndwj" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-zcwb7-cdfc6fd6c-jndwj-hbmf6"}
E0807 03:05:06.330359   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-zcwb7-cdfc6fd6c-jndwj\" not found" "controller"="machine" "name"="md-zcwb7-cdfc6fd6c-jndwj" "namespace"="md-test"
E0807 03:05:06.830051   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5cqz7: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5cqz7" "namespace"="default"
•E0807 03:05:07.415535   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-zcwb7-74d45c49c5-vvjcx\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-zcwb7-74d45c49c5-vvjcx" "namespace"="md-test"
I0807 03:05:07.830970   10671 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-zcwb7-74d45c49c5,md-zcwb7-cdfc6fd6c;Worker machines: md-zcwb7-6657c7fddb-rsqfs,md-zcwb7-74d45c49c5-qpmns,md-zcwb7-74d45c49c5-fgl25,md-zcwb7-6657c7fddb-gfx49,md-zcwb7-cdfc6fd6c-m8tqx,md-zcwb7-74d45c49c5-vvjcx" "indirect descendants count"=8
E0807 03:05:07.837090   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-kccrd: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-kccrd" "namespace"="default"
I0807 03:05:08.416183   10671 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-zcwb7-cdfc6fd6c-m8tqx" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-zcwb7-cdfc6fd6c-m8tqx-q99lb"}
E0807 03:05:08.458403   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-zcwb7-cdfc6fd6c-m8tqx\" not found" "controller"="machine" "name"="md-zcwb7-cdfc6fd6c-m8tqx" "namespace"="md-test"
E0807 03:05:08.838410   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5cqz7: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5cqz7" "namespace"="default"
E0807 03:05:09.464642   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-zcwb7-74d45c49c5-fgl25\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-zcwb7-74d45c49c5-fgl25" "namespace"="md-test"
E0807 03:05:09.851158   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-kccrd: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-kccrd" "namespace"="default"
•E0807 03:05:10.465155   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jqpfq\" for machine \"test-mhc-machine-zpqd2\" in namespace \"test-mhc-8bt4l\": Cluster.cluster.x-k8s.io \"test-cluster-jqpfq\" not found" "controller"="machine" "name"="test-mhc-machine-zpqd2" "namespace"="test-mhc-8bt4l"
E0807 03:05:10.852631   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5cqz7: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5cqz7" "namespace"="default"
E0807 03:05:11.499775   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-jqpfq\" for machine \"test-mhc-machine-ztbcr\" in namespace \"test-mhc-8bt4l\": Cluster.cluster.x-k8s.io \"test-cluster-jqpfq\" not found" "controller"="machine" "name"="test-mhc-machine-ztbcr" "namespace"="test-mhc-8bt4l"
E0807 03:05:11.853758   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-kccrd: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-kccrd" "namespace"="default"
I0807 03:05:12.505658   10671 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-zcwb7-6657c7fddb-gfx49" "namespace"="md-test" 
I0807 03:05:12.505709   10671 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-zcwb7-6657c7fddb-gfx49" "namespace"="md-test" 
I0807 03:05:12.511875   10671 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-zcwb7-6657c7fddb-rsqfs" "namespace"="md-test" 
I0807 03:05:12.511944   10671 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-zcwb7-6657c7fddb-rsqfs" "namespace"="md-test" 
E0807 03:05:12.519619   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-zcwb7-74d45c49c5-vvjcx\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-zcwb7-74d45c49c5-vvjcx" "namespace"="md-test"
E0807 03:05:12.868398   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5cqz7: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5cqz7" "namespace"="default"
E0807 03:05:13.526047   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-zcwb7-74d45c49c5-fgl25\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-zcwb7-74d45c49c5-fgl25" "namespace"="md-test"
E0807 03:05:13.869205   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-kccrd: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-kccrd" "namespace"="default"
E0807 03:05:14.540283   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-zcwb7-74d45c49c5-vvjcx\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-zcwb7-74d45c49c5-vvjcx" "namespace"="md-test"
I0807 03:05:14.869995   10671 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-zcwb7-74d45c49c5,md-zcwb7-cdfc6fd6c;Worker machines: md-zcwb7-6657c7fddb-gfx49,md-zcwb7-74d45c49c5-vvjcx,md-zcwb7-6657c7fddb-rsqfs,md-zcwb7-74d45c49c5-qpmns,md-zcwb7-74d45c49c5-fgl25" "indirect descendants count"=7
E0807 03:05:14.870758   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5cqz7: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5cqz7" "namespace"="default"
I0807 03:05:15.566724   10671 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-zcwb7-6657c7fddb-gfx49" "namespace"="md-test" 
I0807 03:05:15.566812   10671 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-zcwb7-6657c7fddb-gfx49" "namespace"="md-test" 
I0807 03:05:15.574765   10671 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-zcwb7-6657c7fddb-rsqfs" "namespace"="md-test" 
I0807 03:05:15.574991   10671 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-zcwb7-6657c7fddb-rsqfs" "namespace"="md-test" 
E0807 03:05:15.588405   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-zcwb7-74d45c49c5-fgl25\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-zcwb7-74d45c49c5-fgl25" "namespace"="md-test"
E0807 03:05:15.871620   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-kccrd: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-kccrd" "namespace"="default"
E0807 03:05:16.594273   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-zcwb7-74d45c49c5-vvjcx\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-zcwb7-74d45c49c5-vvjcx" "namespace"="md-test"
E0807 03:05:16.872391   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5cqz7: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5cqz7" "namespace"="default"
I0807 03:05:17.611716   10671 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-c2mgv" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0807 03:05:17.634157   10671 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-c2mgv" "namespace"="default" 
E0807 03:05:17.654700   10671 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-c2mgv" "namespace"="default"
E0807 03:05:17.873314   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-kccrd: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-kccrd" "namespace"="default"
E0807 03:05:18.662723   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-zcwb7-74d45c49c5-fgl25\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-zcwb7-74d45c49c5-fgl25" "namespace"="md-test"
E0807 03:05:18.874480   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-kccrd: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-kccrd" "namespace"="default"
I0807 03:05:19.668368   10671 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-zcwb7-6657c7fddb-gfx49" "namespace"="md-test" 
I0807 03:05:19.668425   10671 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-zcwb7-6657c7fddb-gfx49" "namespace"="md-test" 
I0807 03:05:19.674509   10671 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-zcwb7-6657c7fddb-rsqfs" "namespace"="md-test" 
I0807 03:05:19.674569   10671 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-zcwb7-6657c7fddb-rsqfs" "namespace"="md-test" 
E0807 03:05:19.680991   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-zcwb7-74d45c49c5-vvjcx\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-zcwb7-74d45c49c5-vvjcx" "namespace"="md-test"
E0807 03:05:19.875551   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5cqz7: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5cqz7" "namespace"="default"
I0807 03:05:20.696642   10671 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-c2mgv" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0807 03:05:20.696991   10671 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-c2mgv" "namespace"="default" "noderef"="id-node-1"
E0807 03:05:20.714634   10671 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-c2mgv" "namespace"="default"
E0807 03:05:20.876721   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-kccrd: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-kccrd" "namespace"="default"
E0807 03:05:21.719313   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-zcwb7-74d45c49c5-fgl25\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-zcwb7-74d45c49c5-fgl25" "namespace"="md-test"
I0807 03:05:21.877606   10671 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-zcwb7-74d45c49c5,md-zcwb7-cdfc6fd6c;Worker machines: md-zcwb7-6657c7fddb-rsqfs,md-zcwb7-74d45c49c5-qpmns,md-zcwb7-74d45c49c5-fgl25,md-zcwb7-6657c7fddb-gfx49,md-zcwb7-74d45c49c5-vvjcx" "indirect descendants count"=7
E0807 03:05:21.882283   10671 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-kccrd: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-kccrd" "namespace"="default"

------------------------------
• [SLOW TEST:11.972 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 4 lines ...
I0807 03:05:22.084383   10671 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-lhdcm-xs8f2\"" "machineset"="ms-lhdcm" "namespace"="ms-test" 
I0807 03:05:22.084448   10671 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-lhdcm" "namespace"="ms-test" 
I0807 03:05:22.104965   10671 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-lhdcm-78kct\"" "machineset"="ms-lhdcm" "namespace"="ms-test" 
I0807 03:05:22.194104   10671 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-lhdcm" "namespace"="ms-test" "creating"=1 "need"=2
I0807 03:05:22.194162   10671 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-lhdcm" "namespace"="ms-test" 
I0807 03:05:22.206837   10671 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-lhdcm-68v2j\"" "machineset"="ms-lhdcm" "namespace"="ms-test" 
E0807 03:05:22.442124   10671 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-lhdcm-xs8f2-6t5x2 for machine ms-test/ms-lhdcm-xs8f2: the cache is not started, can not read objects" "machineset"="ms-lhdcm" "namespace"="ms-test" 
E0807 03:05:22.671760   10671 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="ms-test/test-cluster"
•I0807 03:05:22.675183   10671 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"
I0807 03:05:22.676026   10671 machine_controller_phases.go:219]  "msg"="Bootstrap provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0807 03:05:22.676073   10671 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"
I0807 03:05:22.676686   10671 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0807 03:05:22.676717   10671 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0807 03:05:22.677210   10671 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 ...
I0807 03:05:22.685801   10671 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"
•I0807 03:05:22.687357   10671 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"
I0807 03:05:22.688165   10671 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"
I0807 03:05:22.688803   10671 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0807 03:05:22.688833   10671 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0807 03:05:22.689335   10671 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0807 03:05:22.690648   10671 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 25.465 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (25.47s)
PASS
Tearing down test suite
I0807 03:05:22.692324   10671 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0807 03:05:22.692367   10671 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I0807 03:05:22.692447   10671 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0807 03:05:22.692514   10671 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0807 03:05:22.692470   10671 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0807 03:05:22.692568   10671 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0807 03:05:22.692626   10671 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-260801918/tls.crt: no such file or directory"  
I0807 03:05:22.692679   10671 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
I0807 03:05:22.692713   10671 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
E0807 03:05:22.741517   10671 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:39451/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1343&timeout=10s&timeoutSeconds=519&watch=true: dial tcp 127.0.0.1:39451: connect: connection refused
E0807 03:05:22.741616   10671 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:39451/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1343&timeout=10s&timeoutSeconds=540&watch=true: dial tcp 127.0.0.1:39451: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	86.088s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 261 lines ...
I0807 03:04:16.109513   11152 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0807 03:04:16.113135   11152 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":{}}}
I0807 03:04:16.513604   11152 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0807 03:04:16.513676   11152 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0807 03:04:16.743375   11152 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0807 03:04:17.196717   11152 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
E0807 03:04:19.267557   11152 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-hhgn6/test-cluster"
•E0807 03:04:19.784020   11152 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-wbbg6/test-cluster"
•E0807 03:04:20.385281   11152 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:45515/?timeout=50ms: dial tcp 127.0.0.1:45515: connect: connection refused"  "cluster"="cluster-cache-test-5vvgf/test-cluster"
•I0807 03:04:20.620361   11152 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}}}
I0807 03:04:20.720831   11152 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="cluster" 
I0807 03:04:20.720903   11152 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
•I0807 03:04:21.009106   11152 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0807 03:04:21.009402   11152 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
E0807 03:04:21.083874   11152 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:38521/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=143&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:38521: connect: connection refused


Ran 5 of 5 Specs in 21.831 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (21.83s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	21.980s
?   	sigs.k8s.io/cluster-api/controllers/remote/fake	[no test files]
?   	sigs.k8s.io/cluster-api/controlplane/kubeadm	[no test files]
=== RUN   TestKubeadmControlPlaneDefault
... skipping 208 lines ...
=== RUN   TestReconcileNoClusterOwnerRef
I0807 03:04:31.964777   11791 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
E0807 03:04:31.968198   11791 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
I0807 03:04:31.969879   11791 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I0807 03:04:31.970319   11791 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcilePaused (0.00s)
=== RUN   TestReconcileClusterNoEndpoints
... skipping 94 lines ...
I0807 03:04:50.336243   11791 remediation.go:248]  "msg"="etcd cluster projected after remediation of m1-unhealthy-lbdrs" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "canSafelyRemediate"=true "healthyMembers"=["node-m2-healthy-rdcqn (m2-healthy-rdcqn)","node-m3-healthy-6psgt (m3-healthy-6psgt)"] "targetQuorum"=2 "targetTotalMembers"=2 "targetUnhealthyMembers"=0 "unhealthyMembers"=[]
I0807 03:04:50.343467   11791 remediation.go:154]  "msg"="Remediating unhealthy machine" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "UnhealthyMachine"="m1-unhealthy-lbdrs"
=== RUN   TestReconcileUnhealthyMachines/Remediation_deletes_unhealthy_machine_-_4_CP_(during_3_CP_rolling_upgrade)
I0807 03:04:50.530520   11791 remediation.go:195]  "msg"="etcd cluster before remediation" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "currentMembers"=["node-m1-unhealthy-29rxn","node-m2-healthy-7gzqp","node-m3-healthy-2vchx","node-m4-healthy-p978h"] "currentTotalMembers"=4
I0807 03:04:50.530622   11791 remediation.go:248]  "msg"="etcd cluster projected after remediation of m1-unhealthy-29rxn" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "canSafelyRemediate"=true "healthyMembers"=["node-m2-healthy-7gzqp (m2-healthy-7gzqp)","node-m3-healthy-2vchx (m3-healthy-2vchx)","node-m4-healthy-p978h (m4-healthy-p978h)"] "targetQuorum"=2 "targetTotalMembers"=3 "targetUnhealthyMembers"=0 "unhealthyMembers"=[]
I0807 03:04:50.536178   11791 remediation.go:154]  "msg"="Remediating unhealthy machine" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "UnhealthyMachine"="m1-unhealthy-29rxn"
--- FAIL: TestReconcileUnhealthyMachines (1.12s)
    --- PASS: TestReconcileUnhealthyMachines/Remediation_does_not_happen_if_there_are_no_unhealthy_machines (0.00s)
    --- PASS: TestReconcileUnhealthyMachines/reconcileUnhealthyMachines_return_early_if_the_machine_to_be_remediated_is_marked_for_deletion (0.00s)
    --- PASS: TestReconcileUnhealthyMachines/Remediation_does_not_happen_if_desired_replicas_<=_1 (0.06s)
    --- PASS: TestReconcileUnhealthyMachines/Remediation_does_not_happen_if_number_of_machines_lower_than_desired (0.09s)
    --- PASS: TestReconcileUnhealthyMachines/Remediation_does_not_happen_if_there_is_a_deleting_machine (0.09s)
    --- PASS: TestReconcileUnhealthyMachines/Remediation_does_not_happen_if_there_is_at_least_one_additional_unhealthy_etcd_member_on_a_3_machine_CP (0.15s)
    --- PASS: TestReconcileUnhealthyMachines/Remediation_does_not_happen_if_there_is_at_least_two_additional_unhealthy_etcd_member_on_a_5_machine_CP (0.19s)
    --- PASS: TestReconcileUnhealthyMachines/Remediation_deletes_unhealthy_machine_-_2_CP_(during_1_CP_rolling_upgrade) (0.11s)
    --- PASS: TestReconcileUnhealthyMachines/Remediation_deletes_unhealthy_machine_-_3_CP (0.17s)
    --- FAIL: TestReconcileUnhealthyMachines/Remediation_deletes_unhealthy_machine_-_4_CP_(during_3_CP_rolling_upgrade) (0.25s)
        remediation_test.go:839: 
            Expected
                <string>: WaitingForRemediation
            to equal
                <string>: RemediationInProgress
=== RUN   TestCanSafelyRemoveEtcdMember
... skipping 80 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
I0807 03:04:54.930836   11791 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
I0807 03:04:54.931034   11791 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: 1659841454
Will run 1 of 1 specs

E0807 03:04:54.966148   11791 controller.go:126]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="Cluster.cluster.x-k8s.io \"kcp-foo-etsj6i\" not found" "kubeadmControlPlane"="kcp-foo-etsj6i" "namespace"="test" 
•

Ran 1 of 1 Specs in 0.030 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (0.03s)
=== RUN   TestKubeadmControlPlaneReconciler_upgradeControlPlane
I0807 03:04:54.969704   11791 controller.go:246]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-zk30n1" "kubeadmControlPlane"="kcp-foo-zk30n1" "namespace"="test" 
I0807 03:04:56.576133   11791 controller.go:331]  "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-zk30n1" "kubeadmControlPlane"="kcp-foo-zk30n1" "namespace"="test" "needRollout"=["kcp-foo-zk30n1-2kx5f"]
I0807 03:04:56.576592   11791 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-zk30n1" "kubeadmControlPlane"="kcp-foo-zk30n1" "namespace"="test" "failures"="[machine kcp-foo-zk30n1-kz74l does not have APIServerPodHealthy condition, machine kcp-foo-zk30n1-kz74l does not have ControllerManagerPodHealthy condition, machine kcp-foo-zk30n1-kz74l does not have SchedulerPodHealthy condition, machine kcp-foo-zk30n1-kz74l does not have EtcdPodHealthy condition, machine kcp-foo-zk30n1-kz74l does not have EtcdMemberHealthy condition]"
--- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (1.61s)
FAIL
I0807 03:04:56.578343   11791 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
FAIL	sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers	42.523s
I0807 03:04:28.695154   11713 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"
I0807 03:04:28.695309   11713 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster"
I0807 03:04:28.695354   11713 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"
I0807 03:04:28.695371   11713 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster"
I0807 03:04:28.695452   11713 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"
I0807 03:04:28.695471   11713 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-machine"
... skipping 51 lines ...
==================================
Random Seed: 1659841452
Will run 7 of 7 specs

•••••••
Ran 7 of 7 Specs in 0.001 seconds
SUCCESS! -- 7 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestControlPlane (0.00s)
=== RUN   TestHasUnhealthyMachine
--- PASS: TestHasUnhealthyMachine (0.00s)
=== RUN   TestNewFailureDomainPicker
=== RUN   TestNewFailureDomainPicker/simple
=== RUN   TestNewFailureDomainPicker/no_machines
... skipping 111 lines ...
=======================================
Random Seed: 1659841452
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
E0807 03:04:32.788489   11713 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"  
E0807 03:04:41.112791   11713 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"  
E0807 03:04:50.098832   11713 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"  
E0807 03:05:01.229180   11713 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"  
E0807 03:05:17.702423   11713 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"  
E0807 03:05:30.711304   11713 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"  
E0807 03:05:48.358876   11713 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"  
E0807 03:06:09.282327   11713 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"  
E0807 03:06:40.298970   11713 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"  
E0807 03:07:25.456236   11713 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
=== RUN   TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_remove_api_endpoint_for_Kubernetes_version_<_1.22.0
=== RUN   TestRemoveMachineFromKubeadmConfigMap/removes_the_machine_node_ref_from_kubeadm_config_for_Kubernetes_version_<_1.22.0
=== RUN   TestRemoveMachineFromKubeadmConfigMap/no_op_for_Kubernetes_version_>=_1.22.0
--- PASS: TestRemoveMachineFromKubeadmConfigMap (172.67s)
    --- PASS: TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil (0.00s)
    --- PASS: TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil (0.00s)
... skipping 83 lines ...
    --- PASS: TestIsKubernetesVersionSupported/workload_cluster_and_version_<_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/workload_cluster_and_version_>=_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_<_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_>=_v1.22.0 (0.00s)
    --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_>=_v1.23.0 (0.00s)
PASS
E0807 03:07:25.466779   11713 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0807 03:07:25.466856   11713 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-786650747/tls.crt: no such file or directory"  
I0807 03:07:25.466785   11713 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/internal	193.513s
=== RUN   TestEtcdMembers_WithErrors
--- PASS: TestEtcdMembers_WithErrors (0.00s)
=== RUN   TestEtcdMembers_WithSuccess
--- PASS: TestEtcdMembers_WithSuccess (0.00s)
... skipping 288 lines ...
I0807 03:04:43.248214   12126 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0807 03:04:43.248317   12126 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"ConfigMap","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0807 03:04:43.348915   12126 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0807 03:04:43.449403   12126 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0807 03:04:43.449493   12126 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0807 03:04:43.556628   12126 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-7qvpim"} 
E0807 03:04:43.592352   12126 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"
•I0807 03:04:44.646527   12126 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-edrjw7"} 
E0807 03:04:44.685159   12126 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"
•E0807 03:04:45.795690   12126 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get data field from the resource" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
E0807 03:04:46.835277   12126 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"
•E0807 03:04:48.080005   12126 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"
•E0807 03:04:49.183659   12126 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"
E0807 03:04:50.207251   12126 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"
•I0807 03:04:50.211984   12126 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
I0807 03:04:50.212087   12126 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0807 03:04:50.212339   12126 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 
E0807 03:04:50.212582   12126 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0807 03:04:50.212709   12126 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-273478645/tls.crt: no such file or directory"  
E0807 03:04:50.213090   12126 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0807 03:04:50.213132   12126 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-273478645/tls.crt: no such file or directory"  


Ran 5 of 5 Specs in 24.252 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (24.25s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/addons/controllers	24.327s
?   	sigs.k8s.io/cluster-api/exp/addons/controllers/predicates	[no test files]
=== RUN   TestMachinePoolDefault
=== RUN   TestMachinePoolDefault/for_MachinePool
... skipping 61 lines ...
    --- PASS: TestReconcileMachinePoolBootstrap/new_machinepool,_no_bootstrap_config_or_data (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_data_should_not_change (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_provider_is_to_not_ready (0.00s)
=== RUN   TestReconcileMachinePoolInfrastructure
=== RUN   TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready
=== RUN   TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed
E0807 03:04:31.365238   12301 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 ...
•I0807 03:04:47.605564   12301 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0807 03:04:47.661302   12301 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0807 03:04:47.666786   12301 machinepool_controller_phases.go:268]  "msg"="Infrastructure provider is not ready, requeuing" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
•I0807 03:04:47.708929   12301 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0807 03:04:47.742146   12301 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••I0807 03:04:47.746232   12301 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0807 03:04:47.746337   12301 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0807 03:04:47.746442   12301 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-150240398/tls.crt: no such file or directory"  
I0807 03:04:47.755958   12301 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinepool" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}


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

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



Summarizing 1 Failure:

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

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