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

No Test Failures!


Error lines from build-log.txt

... skipping 774 lines ...
I0814 03:07:55.440993    8400 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0814 03:07:55.441873    8400 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0814 03:07:55.442063    8400 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=43429
I0814 03:07:55.442367    8400 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0814 03:07:56.391713    8400 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" 
•I0814 03:07:56.401822    8400 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0814 03:07:56.402076    8400 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0814 03:07:56.402152    8400 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-162123689/tls.crt: no such file or directory"  


Ran 1 of 1 Specs in 13.288 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (13.29s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	49.349s
=== 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 1403 lines ...
I0814 03:07:42.658882   10513 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
=== 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
I0814 03:07:42.754876   10513 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"
2022/08/14 03:07:42 http: TLS handshake error from 127.0.0.1:40898: EOF
I0814 03:07:42.765951   10513 cluster_controller_phases.go:76]  "msg"="Could not find external object for cluster, requeuing" "cluster"="test-cluster" "namespace"="test-namespace" "refGroupVersionKind"={"Group":"infrastructure.cluster.x-k8s.io","Version":"v1alpha3","Kind":"InfrastructureMachine"} "refName"="test"
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infra_config_is_marked_for_deletion
I0814 03:07:42.767319   10513 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test-cluster" "namespace"="test-namespace" "err"="cannot create a metadata client without a rest config"
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infrastructure_is_marked_ready_on_cluster
I0814 03:07:42.770479   10513 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test-cluster" "namespace"="test-namespace" "err"="cannot create a metadata client without a rest config"
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_error_if_infrastructure_has_the_paused_annotation
... skipping 100 lines ...
    --- PASS: TestReconcileBootstrap/existing_machine,_machineset_owner_and_version_v1alpha2,_and_ownerref_updated (0.00s)
=== RUN   TestReconcileInfrastructure
=== RUN   TestReconcileInfrastructure/new_machine,_infrastructure_config_ready
I0814 03:07:42.820996   10513 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
I0814 03:07:42.826945   10513 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"
E0814 03:07:42.827447   10513 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
I0814 03:07:42.828223   10513 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.01s)
    --- 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
I0814 03:07:43.226087   10513 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0814 03:07:43.229018   10513 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0814 03:07:43.240223   10513 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-kvrnl" "namespace"="test-machine-watches-5f828" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0814 03:07:43.240362   10513 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0814 03:07:43.363372   10513 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-kvrnl" "namespace"="test-machine-watches-5f828" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0814 03:07:43.363471   10513 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0814 03:07:43.464039   10513 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-kvrnl" "namespace"="test-machine-watches-5f828" "noderef"="node-1"
E0814 03:07:43.474591   10513 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0814 03:07:43.474658   10513 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0814 03:07:43.534096   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"machine-created-kvrnl\" in namespace \"test-machine-watches-5f828\": cannot find node with matching ProviderID" "controller"="machine" "name"="machine-created-kvrnl" "namespace"="test-machine-watches-5f828"
E0814 03:07:44.545731   10513 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-kvrnl\" in namespace \"test-machine-watches-5f828\", requeuing: requeue in 1s"  
E0814 03:07:44.578965   10513 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-kvrnl\" in namespace \"test-machine-watches-5f828\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-kvrnl\" in namespace \"test-machine-watches-5f828\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-kvrnl" "namespace"="test-machine-watches-5f828"
--- PASS: TestWatches (1.86s)
=== RUN   TestIndexMachineByNodeName
=== RUN   TestIndexMachineByNodeName/when_the_machine_has_no_NodeRef
=== RUN   TestIndexMachineByNodeName/when_the_machine_has_valid_a_NodeRef
--- PASS: TestIndexMachineByNodeName (0.00s)
    --- PASS: TestIndexMachineByNodeName/when_the_machine_has_no_NodeRef (0.00s)
... skipping 2 lines ...
=== RUN   TestMachine_Reconcile/reconcile_create
I0814 03:07:44.778261   10513 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-2mldc" "namespace"="test-machine-watches-5f828" "count"=1
I0814 03:07:44.778319   10513 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-2mldc" "namespace"="test-machine-watches-5f828" "descendants"="Worker machines: machine-created-kvrnl" "indirect descendants count"=0
I0814 03:07:44.805429   10513 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-2mldc" "namespace"="test-machine-watches-5f828" "count"=1
I0814 03:07:44.805490   10513 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-2mldc" "namespace"="test-machine-watches-5f828" "descendants"="Worker machines: machine-created-kvrnl" "indirect descendants count"=0
I0814 03:07:45.586678   10513 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-2mldc" "machine"="machine-created-kvrnl" "namespace"="test-machine-watches-5f828" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"6a16a33f-78d1-4069-9e92-69682508d2be","apiVersion":"v1"}
E0814 03:07:45.652957   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-kvrnl\" not found" "controller"="machine" "name"="machine-created-kvrnl" "namespace"="test-machine-watches-5f828"
E0814 03:07:46.706684   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-lsdt4\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-kt72s\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-kt72s: secrets \"machine-reconcile-kt72s-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-lsdt4" "namespace"="default"
I0814 03:07:47.714613   10513 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-kt72s" "machine"="machine-created-lsdt4" "namespace"="default" "cause"="noderef is nil" "node"=null
I0814 03:07:47.752393   10513 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-kt72s" "machine"="machine-created-lsdt4" "namespace"="default" "cause"="noderef is nil" "node"=null
I0814 03:07:47.781304   10513 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-kt72s" "machine"="machine-created-lsdt4" "namespace"="default" "cause"="noderef is nil" "node"=null
E0814 03:07:47.837850   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-lsdt4\" not found" "controller"="machine" "name"="machine-created-lsdt4" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.17s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.17s)
=== RUN   TestMachineFinalizer
=== RUN   TestMachineFinalizer/should_add_a_machine_finalizer_to_the_machine_if_it_doesn't_have_one
=== RUN   TestMachineFinalizer/should_append_the_machine_finalizer_to_the_machine_if_it_already_has_a_finalizer
--- PASS: TestMachineFinalizer (0.00s)
    --- PASS: TestMachineFinalizer/should_add_a_machine_finalizer_to_the_machine_if_it_doesn't_have_one (0.00s)
    --- PASS: TestMachineFinalizer/should_append_the_machine_finalizer_to_the_machine_if_it_already_has_a_finalizer (0.00s)
=== RUN   TestMachineOwnerReference
=== RUN   TestMachineOwnerReference/should_add_owner_reference_to_machine_referencing_a_cluster_with_correct_type_meta
I0814 03:07:47.865701   10513 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine2" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0814 03:07:47.865973   10513 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine2" "namespace"="default" 
E0814 03:07:47.883210   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-kt72s\" not found" "controller"="cluster" "name"="machine-reconcile-kt72s" "namespace"="default"
=== RUN   TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set
I0814 03:07:47.891363   10513 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine3" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0814 03:07:47.891729   10513 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine3" "namespace"="default" 
=== RUN   TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner
I0814 03:07:47.897141   10513 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine4" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0814 03:07:47.899479   10513 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine4" "namespace"="default" 
... skipping 125 lines ...
    --- PASS: TestMachineDeploymentSyncStatus/scaling_down (0.00s)
=== RUN   TestMachineHealthCheck_Reconcile
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist
I0814 03:07:48.113345   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfc6k" "namespace"="test-mhc-h2sm6" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
I0814 03:07:48.141411   10513 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0814 03:07:48.142809   10513 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-tngdz\" not found"  "cluster"="test-mhc-h2sm6/test-cluster-tngdz"
E0814 03:07:48.150647   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-bfc6k\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-bfc6k\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-bfc6k" "namespace"="test-mhc-h2sm6"
=== 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
I0814 03:07:49.150896   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfc6k" "namespace"="test-mhc-h2sm6" 
I0814 03:07:49.151015   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z7r6s" "namespace"="test-mhc-vt6bn" 
I0814 03:07:49.151053   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7gmlz" "namespace"="test-mhc-k46fl" 
I0814 03:07:49.151088   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-52ncb" "namespace"="test-mhc-bs7dr" 
I0814 03:07:49.218840   10513 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0814 03:07:49.256006   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-52ncb" "namespace"="test-mhc-bs7dr" 
I0814 03:07:49.267240   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-52ncb" "namespace"="test-mhc-bs7dr" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
I0814 03:07:49.270539   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-52ncb" "namespace"="test-mhc-bs7dr" 
E0814 03:07:49.290081   10513 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-bs7dr/test-cluster-rh8pt"
E0814 03:07:49.292985   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-rh8pt\" not found" "controller"="cluster" "name"="test-cluster-rh8pt" "namespace"="test-mhc-bs7dr"
I0814 03:07:49.299204   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xxg7q" "namespace"="test-mhc-w7bgk" 
I0814 03:07:49.336337   10513 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0814 03:07:49.360022   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xxg7q" "namespace"="test-mhc-w7bgk" 
E0814 03:07:49.405633   10513 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-w7bgk/test-cluster-6dqd5"
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0814 03:07:49.410584   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xxg7q" "namespace"="test-mhc-w7bgk" 
I0814 03:07:49.431426   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-px6c8" "namespace"="test-mhc-8kdbk" 
inframachine created: test-mhc-machine-infra-jdm7j
I0814 03:07:49.448251   10513 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-k2sfz
I0814 03:07:49.474267   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-px6c8" "namespace"="test-mhc-8kdbk" 
I0814 03:07:49.474701   10513 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-8kdbk/test-mhc-px6c8/test-mhc-machine-k2sfz/"
I0814 03:07:49.488845   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-px6c8" "namespace"="test-mhc-8kdbk" 
I0814 03:07:49.489156   10513 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-8kdbk/test-mhc-px6c8/test-mhc-machine-k2sfz/"
E0814 03:07:49.556259   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-n6n4p, got []"  "node"="test-mhc-node-n6n4p"
node created: test-mhc-node-n6n4p
E0814 03:07:49.556376   10513 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-n6n4p"
I0814 03:07:49.565976   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-px6c8" "namespace"="test-mhc-8kdbk" 
inframachine created: test-mhc-machine-infra-44dfr
machine created: test-mhc-machine-4c5jr
I0814 03:07:49.598607   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-px6c8" "namespace"="test-mhc-8kdbk" 
I0814 03:07:49.605290   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-px6c8" "namespace"="test-mhc-8kdbk" 
I0814 03:07:49.606405   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-px6c8" "namespace"="test-mhc-8kdbk" 
... skipping 6 lines ...
I0814 03:07:49.637299   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-px6c8" "namespace"="test-mhc-8kdbk" 
I0814 03:07:49.638650   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-px6c8" "namespace"="test-mhc-8kdbk" 
I0814 03:07:49.640449   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-px6c8" "namespace"="test-mhc-8kdbk" 
I0814 03:07:49.643706   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-px6c8" "namespace"="test-mhc-8kdbk" 
I0814 03:07:49.650113   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-px6c8" "namespace"="test-mhc-8kdbk" 
I0814 03:07:49.668764   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-px6c8" "namespace"="test-mhc-8kdbk" 
I0814 03:07:49.670889   10513 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-8kdbk/test-mhc-px6c8/test-mhc-machine-4c5jr/"
E0814 03:07:49.693710   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-r9h47, got []"  "node"="test-mhc-node-r9h47"
E0814 03:07:49.693972   10513 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-r9h47"
node created: test-mhc-node-r9h47
I0814 03:07:49.705385   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-px6c8" "namespace"="test-mhc-8kdbk" 
I0814 03:07:49.706113   10513 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-8kdbk/test-mhc-px6c8/test-mhc-machine-4c5jr/"
I0814 03:07:49.708466   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-px6c8" "namespace"="test-mhc-8kdbk" 
I0814 03:07:49.714144   10513 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-4c5jr" "namespace"="test-mhc-8kdbk" "noderef"="test-mhc-node-r9h47"
I0814 03:07:49.740118   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-px6c8" "namespace"="test-mhc-8kdbk" 
Cleaning up nodes, machines and infra machines.
I0814 03:07:49.751503   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-px6c8" "namespace"="test-mhc-8kdbk" 
I0814 03:07:49.753271   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-px6c8" "namespace"="test-mhc-8kdbk" 
I0814 03:07:49.758799   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-px6c8" "namespace"="test-mhc-8kdbk" 
I0814 03:07:49.759302   10513 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-8kdbk/test-mhc-px6c8/test-mhc-machine-k2sfz/"
E0814 03:07:49.799413   10513 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-8kdbk/test-cluster-ztb48"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
inframachine created: test-mhc-machine-infra-pv26w
machine created: test-mhc-machine-jbncs
E0814 03:07:49.930388   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-px6c8\" not found" "controller"="machinehealthcheck" "name"="test-mhc-px6c8" "namespace"="test-mhc-8kdbk"
E0814 03:07:49.978831   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"test-mhc-machine-k2sfz\" in namespace \"test-mhc-8kdbk\": cannot find node with matching ProviderID" "controller"="machine" "name"="test-mhc-machine-k2sfz" "namespace"="test-mhc-8kdbk"
E0814 03:07:50.307856   10513 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-5f828/machine-reconcile-2mldc"
I0814 03:07:50.930694   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:50.948647   10513 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0814 03:07:50.971386   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-px6c8" "namespace"="test-mhc-8kdbk" 
I0814 03:07:50.971471   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:50.972515   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:50.974498   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:50.976350   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:50.978382   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
E0814 03:07:50.979096   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ztb48\" for machine \"test-mhc-machine-4c5jr\" in namespace \"test-mhc-8kdbk\": Cluster.cluster.x-k8s.io \"test-cluster-ztb48\" not found" "controller"="machine" "name"="test-mhc-machine-4c5jr" "namespace"="test-mhc-8kdbk"
I0814 03:07:50.980724   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:50.982836   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:50.985168   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:50.987307   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:50.989535   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:50.991589   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
... skipping 413 lines ...
I0814 03:07:51.984342   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:51.986686   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:51.988539   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:51.990303   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:51.992373   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:51.994182   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:51.994471   10513 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-nrhs9/test-mhc-59565/test-mhc-machine-jbncs/"
E0814 03:07:51.994824   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ztb48\" for machine \"test-mhc-machine-k2sfz\" in namespace \"test-mhc-8kdbk\": Cluster.cluster.x-k8s.io \"test-cluster-ztb48\" not found" "controller"="machine" "name"="test-mhc-machine-k2sfz" "namespace"="test-mhc-8kdbk"
I0814 03:07:52.007148   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:52.007495   10513 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-nrhs9/test-mhc-59565/test-mhc-machine-jbncs/"
E0814 03:07:52.081859   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-qdcfp, got []"  "node"="test-mhc-node-qdcfp"
node created: test-mhc-node-qdcfp
I0814 03:07:52.093448   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
inframachine created: test-mhc-machine-infra-xkg79
machine created: test-mhc-machine-5ngn6
I0814 03:07:52.116406   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:52.124014   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
... skipping 287 lines ...
I0814 03:07:52.983282   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:52.985536   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:52.987698   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:52.989892   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:52.992077   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:52.994251   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
E0814 03:07:52.995179   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ztb48\" for machine \"test-mhc-machine-4c5jr\" in namespace \"test-mhc-8kdbk\": Cluster.cluster.x-k8s.io \"test-cluster-ztb48\" not found" "controller"="machine" "name"="test-mhc-machine-4c5jr" "namespace"="test-mhc-8kdbk"
I0814 03:07:52.997056   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:52.999276   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:53.001587   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:53.003848   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:53.006045   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:53.008202   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
... skipping 375 lines ...
I0814 03:07:54.053156   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:54.054696   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:54.056202   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:54.057667   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:54.067372   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:54.068479   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
E0814 03:07:54.069328   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ztb48\" for machine \"test-mhc-machine-k2sfz\" in namespace \"test-mhc-8kdbk\": Cluster.cluster.x-k8s.io \"test-cluster-ztb48\" not found" "controller"="machine" "name"="test-mhc-machine-k2sfz" "namespace"="test-mhc-8kdbk"
I0814 03:07:54.069551   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:54.070637   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:54.072857   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:54.074996   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:54.077204   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:54.079420   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
... skipping 358 lines ...
I0814 03:07:55.101689   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:55.104085   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:55.106369   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:55.108644   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:55.110887   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:55.113263   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:55.113633   10513 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-nrhs9/test-mhc-59565/test-mhc-machine-5ngn6/"
E0814 03:07:55.113650   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ztb48\" for machine \"test-mhc-machine-4c5jr\" in namespace \"test-mhc-8kdbk\": Cluster.cluster.x-k8s.io \"test-cluster-ztb48\" not found" "controller"="machine" "name"="test-mhc-machine-4c5jr" "namespace"="test-mhc-8kdbk"
I0814 03:07:55.124267   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:55.124685   10513 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-nrhs9/test-mhc-59565/test-mhc-machine-5ngn6/"
E0814 03:07:55.133467   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-b2fr2, got []"  "node"="test-mhc-node-b2fr2"
node created: test-mhc-node-b2fr2
I0814 03:07:55.140748   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
inframachine created: test-mhc-machine-infra-hflzm
machine created: test-mhc-machine-wwlg7
I0814 03:07:55.163288   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:55.169842   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
... skipping 266 lines ...
I0814 03:07:56.088953   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:56.091489   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:56.093992   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:56.106726   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:56.111488   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:56.117697   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
E0814 03:07:56.127251   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ztb48\" for machine \"test-mhc-machine-k2sfz\" in namespace \"test-mhc-8kdbk\": Cluster.cluster.x-k8s.io \"test-cluster-ztb48\" not found" "controller"="machine" "name"="test-mhc-machine-k2sfz" "namespace"="test-mhc-8kdbk"
I0814 03:07:56.129696   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:56.132050   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:56.153865   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:56.155320   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:56.156652   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:56.159289   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
... skipping 275 lines ...
I0814 03:07:57.142262   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:57.146842   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:57.151480   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:57.154144   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:57.157116   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:57.166197   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
E0814 03:07:57.166578   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ztb48\" for machine \"test-mhc-machine-4c5jr\" in namespace \"test-mhc-8kdbk\": Cluster.cluster.x-k8s.io \"test-cluster-ztb48\" not found" "controller"="machine" "name"="test-mhc-machine-4c5jr" "namespace"="test-mhc-8kdbk"
I0814 03:07:57.168101   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:57.170066   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:57.172292   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:57.174825   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:57.177304   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:57.180892   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
... skipping 255 lines ...
I0814 03:07:58.167730   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:58.170374   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:58.173225   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:58.175261   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:58.179164   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:58.183320   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:58.183930   10513 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-nrhs9/test-mhc-59565/test-mhc-machine-wwlg7/"
E0814 03:07:58.185191   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ztb48\" for machine \"test-mhc-machine-k2sfz\" in namespace \"test-mhc-8kdbk\": Cluster.cluster.x-k8s.io \"test-cluster-ztb48\" not found" "controller"="machine" "name"="test-mhc-machine-k2sfz" "namespace"="test-mhc-8kdbk"
E0814 03:07:58.200506   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-4sdrt, got []"  "node"="test-mhc-node-4sdrt"
node created: test-mhc-node-4sdrt
I0814 03:07:58.209017   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:58.209734   10513 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-nrhs9/test-mhc-59565/test-mhc-machine-wwlg7/"
Cleaning up nodes, machines and infra machines.
I0814 03:07:58.211315   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:58.212251   10513 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-nrhs9/test-mhc-59565/test-mhc-machine-wwlg7/test-mhc-node-4sdrt"
I0814 03:07:58.238087   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-59565" "namespace"="test-mhc-nrhs9" 
I0814 03:07:58.238723   10513 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-nrhs9/test-mhc-59565/test-mhc-machine-wwlg7/"
Cleaning up nodes, machines and infra machines.
I0814 03:07:58.287853   10513 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-7qxtt" "namespace"="test-mhc-nrhs9" "count"=2
I0814 03:07:58.287953   10513 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-7qxtt" "namespace"="test-mhc-nrhs9" "descendants"="Worker machines: test-mhc-machine-5ngn6,test-mhc-machine-wwlg7,test-mhc-machine-jbncs" "indirect descendants count"=1
I0814 03:07:58.294490   10513 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-7qxtt" "namespace"="test-mhc-nrhs9" "count"=2
I0814 03:07:58.294552   10513 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-7qxtt" "namespace"="test-mhc-nrhs9" "descendants"="Worker machines: test-mhc-machine-jbncs,test-mhc-machine-5ngn6,test-mhc-machine-wwlg7" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
... skipping 7 lines ...
I0814 03:07:58.584793   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:07:58.625818   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:07:58.706929   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:07:58.867920   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:07:59.185735   10513 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-7qxtt" "machine"="test-mhc-machine-5ngn6" "namespace"="test-mhc-nrhs9" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-b2fr2"}
I0814 03:07:59.188919   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
E0814 03:07:59.244781   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-5ngn6\" not found" "controller"="machine" "name"="test-mhc-machine-5ngn6" "namespace"="test-mhc-nrhs9"
I0814 03:07:59.829919   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
E0814 03:08:00.245239   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ztb48\" for machine \"test-mhc-machine-4c5jr\" in namespace \"test-mhc-8kdbk\": Cluster.cluster.x-k8s.io \"test-cluster-ztb48\" not found" "controller"="machine" "name"="test-mhc-machine-4c5jr" "namespace"="test-mhc-8kdbk"
I0814 03:08:01.111005   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:08:01.245757   10513 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-7qxtt" "machine"="test-mhc-machine-wwlg7" "namespace"="test-mhc-nrhs9" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-4sdrt"}
E0814 03:08:01.291573   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-wwlg7\" not found" "controller"="machine" "name"="test-mhc-machine-wwlg7" "namespace"="test-mhc-nrhs9"
E0814 03:08:02.291959   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ztb48\" for machine \"test-mhc-machine-k2sfz\" in namespace \"test-mhc-8kdbk\": Cluster.cluster.x-k8s.io \"test-cluster-ztb48\" not found" "controller"="machine" "name"="test-mhc-machine-k2sfz" "namespace"="test-mhc-8kdbk"
I0814 03:08:03.292605   10513 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-7qxtt" "machine"="test-mhc-machine-jbncs" "namespace"="test-mhc-nrhs9" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-qdcfp"}
I0814 03:08:03.297859   10513 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-7qxtt" "namespace"="test-mhc-nrhs9" "count"=1
I0814 03:08:03.297944   10513 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-7qxtt" "namespace"="test-mhc-nrhs9" "descendants"="Worker machines: test-mhc-machine-jbncs" "indirect descendants count"=0
E0814 03:08:03.341454   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-jbncs\" not found" "controller"="machine" "name"="test-mhc-machine-jbncs" "namespace"="test-mhc-nrhs9"
I0814 03:08:03.672108   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:08:04.350695   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:08:04.356089   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
E0814 03:08:04.356403   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ztb48\" for machine \"test-mhc-machine-4c5jr\" in namespace \"test-mhc-8kdbk\": Cluster.cluster.x-k8s.io \"test-cluster-ztb48\" not found" "controller"="machine" "name"="test-mhc-machine-4c5jr" "namespace"="test-mhc-8kdbk"
I0814 03:08:04.377304   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
node created: test-mhc-node-8q8tr
E0814 03:08:04.386648   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8q8tr, got []"  "node"="test-mhc-node-8q8tr"
E0814 03:08:04.386876   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8q8tr, got []"  "node"="test-mhc-node-8q8tr"
I0814 03:08:04.402162   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
inframachine created: test-mhc-machine-infra-pvh7g
machine created: test-mhc-machine-7f22f
I0814 03:08:04.441497   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:08:04.467212   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:08:04.472466   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:08:04.493719   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:08:04.536449   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:08:04.617941   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:08:04.779725   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:08:05.106441   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
E0814 03:08:05.356825   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ztb48\" for machine \"test-mhc-machine-k2sfz\" in namespace \"test-mhc-8kdbk\": Cluster.cluster.x-k8s.io \"test-cluster-ztb48\" not found" "controller"="machine" "name"="test-mhc-machine-k2sfz" "namespace"="test-mhc-8kdbk"
I0814 03:08:05.748085   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:08:06.370514   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:08:06.371505   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:08:06.379042   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:08:06.414792   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:08:06.424033   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:08:06.440263   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:08:06.448457   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
E0814 03:08:06.449752   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ztb48\" for machine \"test-mhc-machine-4c5jr\" in namespace \"test-mhc-8kdbk\": Cluster.cluster.x-k8s.io \"test-cluster-ztb48\" not found" "controller"="machine" "name"="test-mhc-machine-4c5jr" "namespace"="test-mhc-8kdbk"
I0814 03:08:06.472526   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
E0814 03:08:06.539333   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zxgkz, got []"  "node"="test-mhc-node-zxgkz"
node created: test-mhc-node-zxgkz
E0814 03:08:06.539524   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zxgkz, got []"  "node"="test-mhc-node-zxgkz"
I0814 03:08:06.547342   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
inframachine created: test-mhc-machine-infra-nt4gc
I0814 03:08:06.557771   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:08:06.563797   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
machine created: test-mhc-machine-nmmsv
I0814 03:08:06.576467   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:08:06.582767   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:08:07.029465   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
E0814 03:08:07.450118   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ztb48\" for machine \"test-mhc-machine-k2sfz\" in namespace \"test-mhc-8kdbk\": Cluster.cluster.x-k8s.io \"test-cluster-ztb48\" not found" "controller"="machine" "name"="test-mhc-machine-k2sfz" "namespace"="test-mhc-8kdbk"
E0814 03:08:08.311236   10513 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-nrhs9/test-cluster-7qxtt"
I0814 03:08:08.461694   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:08:08.484834   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:08:08.491487   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:08:08.503466   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:08:08.509569   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:08:08.519259   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:08:08.525885   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
E0814 03:08:08.534545   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ztb48\" for machine \"test-mhc-machine-4c5jr\" in namespace \"test-mhc-8kdbk\": Cluster.cluster.x-k8s.io \"test-cluster-ztb48\" not found" "controller"="machine" "name"="test-mhc-machine-4c5jr" "namespace"="test-mhc-8kdbk"
I0814 03:08:08.571113   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
E0814 03:08:08.591143   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zbcv6, got []"  "node"="test-mhc-node-zbcv6"
node created: test-mhc-node-zbcv6
I0814 03:08:08.599126   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
Cleaning up nodes, machines and infra machines.
I0814 03:08:08.615417   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:08:08.640420   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
Cleaning up nodes, machines and infra machines.
I0814 03:08:08.647437   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:08:08.664895   10513 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-jjfqz" "namespace"="test-mhc-q89hp" "count"=2
I0814 03:08:08.664984   10513 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-jjfqz" "namespace"="test-mhc-q89hp" "descendants"="Worker machines: test-mhc-machine-mdnbp,test-mhc-machine-7f22f,test-mhc-machine-nmmsv" "indirect descendants count"=1
I0814 03:08:08.672063   10513 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-jjfqz" "namespace"="test-mhc-q89hp" "count"=2
I0814 03:08:08.672128   10513 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-jjfqz" "namespace"="test-mhc-q89hp" "descendants"="Worker machines: test-mhc-machine-mdnbp,test-mhc-machine-7f22f,test-mhc-machine-nmmsv" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_less_than_the_NodeStartupTimeout
E0814 03:08:08.794193   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-d8rxt\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-d8rxt\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp"
inframachine created: test-mhc-machine-infra-r5ldq
machine created: test-mhc-machine-9n9xf
E0814 03:08:09.534935   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ztb48\" for machine \"test-mhc-machine-k2sfz\" in namespace \"test-mhc-8kdbk\": Cluster.cluster.x-k8s.io \"test-cluster-ztb48\" not found" "controller"="machine" "name"="test-mhc-machine-k2sfz" "namespace"="test-mhc-8kdbk"
I0814 03:08:09.794515   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8rxt" "namespace"="test-mhc-q89hp" 
I0814 03:08:09.794621   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4nq44" "namespace"="test-mhc-jt7nh" 
I0814 03:08:09.819185   10513 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0814 03:08:09.855083   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4nq44" "namespace"="test-mhc-jt7nh" 
I0814 03:08:10.535461   10513 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-jjfqz" "machine"="test-mhc-machine-mdnbp" "namespace"="test-mhc-q89hp" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-8q8tr"}
E0814 03:08:10.586594   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-mdnbp\" not found" "controller"="machine" "name"="test-mhc-machine-mdnbp" "namespace"="test-mhc-q89hp"
I0814 03:08:11.590622   10513 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-jjfqz" "machine"="test-mhc-machine-7f22f" "namespace"="test-mhc-q89hp" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-zxgkz"}
E0814 03:08:11.661915   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-7f22f\" not found" "controller"="machine" "name"="test-mhc-machine-7f22f" "namespace"="test-mhc-q89hp"
I0814 03:08:12.662665   10513 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-jjfqz" "machine"="test-mhc-machine-nmmsv" "namespace"="test-mhc-q89hp" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-zbcv6"}
E0814 03:08:12.705055   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-nmmsv\" not found" "controller"="machine" "name"="test-mhc-machine-nmmsv" "namespace"="test-mhc-q89hp"
E0814 03:08:13.695446   10513 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-q89hp/test-cluster-jjfqz"
I0814 03:08:13.714456   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4nq44" "namespace"="test-mhc-jt7nh" 
I0814 03:08:13.718876   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4nq44" "namespace"="test-mhc-jt7nh" 
E0814 03:08:13.719913   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ztb48\" for machine \"test-mhc-machine-4c5jr\" in namespace \"test-mhc-8kdbk\": Cluster.cluster.x-k8s.io \"test-cluster-ztb48\" not found" "controller"="machine" "name"="test-mhc-machine-4c5jr" "namespace"="test-mhc-8kdbk"
node created: test-mhc-node-24hsb
E0814 03:08:13.736263   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-24hsb, got []"  "node"="test-mhc-node-24hsb"
I0814 03:08:13.746435   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4nq44" "namespace"="test-mhc-jt7nh" 
inframachine created: test-mhc-machine-infra-bqt8n
machine created: test-mhc-machine-5l28g
I0814 03:08:13.767016   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4nq44" "namespace"="test-mhc-jt7nh" 
I0814 03:08:13.773826   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4nq44" "namespace"="test-mhc-jt7nh" 
I0814 03:08:13.774928   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4nq44" "namespace"="test-mhc-jt7nh" 
E0814 03:08:14.720461   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ztb48\" for machine \"test-mhc-machine-k2sfz\" in namespace \"test-mhc-8kdbk\": Cluster.cluster.x-k8s.io \"test-cluster-ztb48\" not found" "controller"="machine" "name"="test-mhc-machine-k2sfz" "namespace"="test-mhc-8kdbk"
I0814 03:08:15.734022   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4nq44" "namespace"="test-mhc-jt7nh" 
I0814 03:08:15.741945   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4nq44" "namespace"="test-mhc-jt7nh" 
I0814 03:08:15.752387   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4nq44" "namespace"="test-mhc-jt7nh" 
I0814 03:08:15.757216   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4nq44" "namespace"="test-mhc-jt7nh" 
I0814 03:08:15.766030   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4nq44" "namespace"="test-mhc-jt7nh" 
E0814 03:08:15.775865   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ztb48\" for machine \"test-mhc-machine-4c5jr\" in namespace \"test-mhc-8kdbk\": Cluster.cluster.x-k8s.io \"test-cluster-ztb48\" not found" "controller"="machine" "name"="test-mhc-machine-4c5jr" "namespace"="test-mhc-8kdbk"
I0814 03:08:15.776260   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4nq44" "namespace"="test-mhc-jt7nh" 
E0814 03:08:15.877727   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-mvwsq, got []"  "node"="test-mhc-node-mvwsq"
node created: test-mhc-node-mvwsq
I0814 03:08:15.884798   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4nq44" "namespace"="test-mhc-jt7nh" 
inframachine created: test-mhc-machine-infra-dt8k5
I0814 03:08:15.902978   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4nq44" "namespace"="test-mhc-jt7nh" 
machine created: test-mhc-machine-fwhzm
I0814 03:08:15.908915   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4nq44" "namespace"="test-mhc-jt7nh" 
... skipping 9 lines ...
I0814 03:08:16.907774   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4nq44" "namespace"="test-mhc-jt7nh" 
Cleaning up nodes, machines and infra machines.
I0814 03:08:16.926758   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4nq44" "namespace"="test-mhc-jt7nh" 
Cleaning up nodes, machines and infra machines.
I0814 03:08:16.948513   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4nq44" "namespace"="test-mhc-jt7nh" 
I0814 03:08:16.951418   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4nq44" "namespace"="test-mhc-jt7nh" 
I0814 03:08:16.951994   10513 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-jt7nh/test-mhc-4nq44/test-mhc-machine-9n9xf/"
I0814 03:08:16.992425   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4nq44" "namespace"="test-mhc-jt7nh" 
I0814 03:08:16.993075   10513 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-jt7nh/test-mhc-4nq44/test-mhc-machine-9n9xf/"
I0814 03:08:16.993516   10513 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-jt7nh/test-mhc-4nq44/test-mhc-machine-5l28g/"
E0814 03:08:17.006481   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"test-mhc-machine-5l28g\" in namespace \"test-mhc-jt7nh\": cannot find node with matching ProviderID" "controller"="machine" "name"="test-mhc-machine-5l28g" "namespace"="test-mhc-jt7nh"
I0814 03:08:17.032581   10513 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-rwjtp" "namespace"="test-mhc-jt7nh" "count"=3
I0814 03:08:17.032671   10513 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-rwjtp" "namespace"="test-mhc-jt7nh" "descendants"="Worker machines: test-mhc-machine-9n9xf,test-mhc-machine-5l28g,test-mhc-machine-fwhzm" "indirect descendants count"=0
I0814 03:08:17.040153   10513 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-rwjtp" "namespace"="test-mhc-jt7nh" "count"=3
I0814 03:08:17.040223   10513 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-rwjtp" "namespace"="test-mhc-jt7nh" "descendants"="Worker machines: test-mhc-machine-9n9xf,test-mhc-machine-5l28g,test-mhc-machine-fwhzm" "indirect descendants count"=0
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_longer_than_the_NodeStartupTimeout
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine's_Node_has_gone_away
=== RUN   TestMachineHealthCheck_Reconcile/should_react_when_a_Node_transitions_to_unhealthy
inframachine created: test-mhc-machine-infra-cgd56
machine created: test-mhc-machine-m9ffn
E0814 03:08:17.196108   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-4nq44\" not found" "controller"="machinehealthcheck" "name"="test-mhc-4nq44" "namespace"="test-mhc-jt7nh"
I0814 03:08:18.007049   10513 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-rwjtp" "machine"="test-mhc-machine-fwhzm" "namespace"="test-mhc-jt7nh" "cause"="cluster is being deleted" "node"=null
E0814 03:08:18.058410   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-fwhzm\" not found" "controller"="machine" "name"="test-mhc-machine-fwhzm" "namespace"="test-mhc-jt7nh"
I0814 03:08:18.196409   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:18.245585   10513 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0814 03:08:18.371122   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4nq44" "namespace"="test-mhc-jt7nh" 
I0814 03:08:18.371192   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:18.372226   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:18.374007   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
... skipping 337 lines ...
I0814 03:08:19.114285   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:19.116057   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:19.117835   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:19.119608   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:19.121315   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:19.123014   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
E0814 03:08:19.123959   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-9n9xf\" not found" "controller"="machine" "name"="test-mhc-machine-9n9xf" "namespace"="test-mhc-jt7nh"
I0814 03:08:19.124746   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:19.126323   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:19.128198   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:19.129975   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:19.131667   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:19.133599   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
... skipping 446 lines ...
I0814 03:08:20.187179   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:20.190464   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:20.192708   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:20.194739   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:20.196856   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:20.199014   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
E0814 03:08:20.200250   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-5l28g\" not found" "controller"="machine" "name"="test-mhc-machine-5l28g" "namespace"="test-mhc-jt7nh"
I0814 03:08:20.201999   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:20.203835   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:20.205753   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:20.207652   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:20.209718   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:20.211619   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
... skipping 448 lines ...
I0814 03:08:21.209986   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:21.218006   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:21.220317   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:21.222228   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:21.224455   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:21.225189   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:21.225541   10513 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-qnm6m/test-mhc-x74m4/test-mhc-machine-m9ffn/"
E0814 03:08:21.225586   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ztb48\" for machine \"test-mhc-machine-k2sfz\" in namespace \"test-mhc-8kdbk\": Cluster.cluster.x-k8s.io \"test-cluster-ztb48\" not found" "controller"="machine" "name"="test-mhc-machine-k2sfz" "namespace"="test-mhc-8kdbk"
I0814 03:08:21.237100   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:21.237462   10513 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-qnm6m/test-mhc-x74m4/test-mhc-machine-m9ffn/"
E0814 03:08:21.272506   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-md4hf, got []"  "node"="test-mhc-node-md4hf"
node created: test-mhc-node-md4hf
E0814 03:08:21.272776   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-md4hf, got []"  "node"="test-mhc-node-md4hf"
I0814 03:08:21.280121   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:21.296475   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:21.305961   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:21.306331   10513 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-qnm6m/test-mhc-x74m4/test-mhc-machine-m9ffn/test-mhc-node-md4hf"
I0814 03:08:21.322320   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:21.322734   10513 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-qnm6m/test-mhc-x74m4/test-mhc-machine-m9ffn/test-mhc-node-md4hf"
Cleaning up nodes, machines and infra machines.
I0814 03:08:21.328207   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:21.328604   10513 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-qnm6m/test-mhc-x74m4/test-mhc-machine-m9ffn/test-mhc-node-md4hf"
I0814 03:08:21.332467   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:21.332798   10513 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-qnm6m/test-mhc-x74m4/test-mhc-machine-m9ffn/"
I0814 03:08:21.350483   10513 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-6pj5j" "namespace"="test-mhc-qnm6m" "descendants"="Worker machines: test-mhc-machine-m9ffn" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0814 03:08:21.360360   10513 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-6pj5j" "namespace"="test-mhc-qnm6m" "descendants"="Worker machines: test-mhc-machine-m9ffn" "indirect descendants count"=1
I0814 03:08:21.482094   10513 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-fgkll" "namespace"="test-mhc-52lgr" "creating"=1 "need"=1
I0814 03:08:21.482151   10513 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-fgkll" "namespace"="test-mhc-52lgr" 
I0814 03:08:21.504777   10513 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-fgkll-g6j6c\"" "machineset"="mhc-ms-fgkll" "namespace"="test-mhc-52lgr" 
I0814 03:08:21.518325   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x74m4" "namespace"="test-mhc-qnm6m" 
I0814 03:08:21.577384   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fzt2s" "namespace"="test-mhc-52lgr" 
I0814 03:08:21.614123   10513 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0814 03:08:21.639855   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fzt2s" "namespace"="test-mhc-52lgr" 
E0814 03:08:22.056079   10513 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-jt7nh/test-cluster-rwjtp"
E0814 03:08:22.226074   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ztb48\" for machine \"test-mhc-machine-4c5jr\" in namespace \"test-mhc-8kdbk\": Cluster.cluster.x-k8s.io \"test-cluster-ztb48\" not found" "controller"="machine" "name"="test-mhc-machine-4c5jr" "namespace"="test-mhc-8kdbk"
I0814 03:08:22.640154   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fzt2s" "namespace"="test-mhc-52lgr" 
I0814 03:08:23.226618   10513 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-6pj5j" "machine"="test-mhc-machine-m9ffn" "namespace"="test-mhc-qnm6m" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-md4hf"}
E0814 03:08:23.279703   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-m9ffn\" not found" "controller"="machine" "name"="test-mhc-machine-m9ffn" "namespace"="test-mhc-qnm6m"
I0814 03:08:23.641182   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fzt2s" "namespace"="test-mhc-52lgr" 
I0814 03:08:24.288783   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fzt2s" "namespace"="test-mhc-52lgr" 
I0814 03:08:24.289657   10513 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-fgkll" "namespace"="test-mhc-52lgr" 
I0814 03:08:24.294951   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fzt2s" "namespace"="test-mhc-52lgr" 
I0814 03:08:24.295745   10513 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-fgkll" "namespace"="test-mhc-52lgr" 
I0814 03:08:24.304980   10513 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-fgkll-g6j6c" "namespace"="test-mhc-52lgr" 
... skipping 7 lines ...
I0814 03:08:24.331089   10513 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-fgkll-g6j6c" "namespace"="test-mhc-52lgr" 
I0814 03:08:24.331135   10513 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-fgkll-g6j6c" "namespace"="test-mhc-52lgr" 
I0814 03:08:24.642252   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fzt2s" "namespace"="test-mhc-52lgr" 
I0814 03:08:25.322916   10513 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-fgkll-g6j6c" "namespace"="test-mhc-52lgr" 
I0814 03:08:25.322969   10513 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-fgkll-g6j6c" "namespace"="test-mhc-52lgr" 
I0814 03:08:26.000682   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fzt2s" "namespace"="test-mhc-52lgr" 
I0814 03:08:26.001142   10513 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-52lgr/test-mhc-fzt2s/mhc-ms-fgkll-g6j6c/"
I0814 03:08:26.008337   10513 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-fgkll" "namespace"="test-mhc-52lgr" 
I0814 03:08:26.013456   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fzt2s" "namespace"="test-mhc-52lgr" 
I0814 03:08:26.013814   10513 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-52lgr/test-mhc-fzt2s/mhc-ms-fgkll-g6j6c/"
I0814 03:08:26.014399   10513 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-fgkll-g6j6c" "namespace"="test-mhc-52lgr" 
I0814 03:08:26.014425   10513 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-fgkll-g6j6c" "namespace"="test-mhc-52lgr" 
I0814 03:08:26.024015   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fzt2s" "namespace"="test-mhc-52lgr" 
I0814 03:08:26.024605   10513 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-52lgr/test-mhc-fzt2s/mhc-ms-fgkll-g6j6c/"
I0814 03:08:26.025477   10513 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-fgkll" "namespace"="test-mhc-52lgr" 
I0814 03:08:26.038632   10513 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-fgkll-g6j6c" "namespace"="test-mhc-52lgr" 
I0814 03:08:26.038842   10513 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-fgkll-g6j6c" "namespace"="test-mhc-52lgr" 
I0814 03:08:26.117706   10513 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-7cbdd" "namespace"="test-mhc-52lgr" "count"=1
I0814 03:08:26.117770   10513 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-7cbdd" "namespace"="test-mhc-52lgr" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-fgkll"
I0814 03:08:26.118566   10513 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-fgkll" "namespace"="test-mhc-52lgr" "machine"="mhc-ms-fgkll-g6j6c"
I0814 03:08:26.123879   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fzt2s" "namespace"="test-mhc-52lgr" 
I0814 03:08:26.124198   10513 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-52lgr/test-mhc-fzt2s/mhc-ms-fgkll-g6j6c/"
I0814 03:08:26.125075   10513 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-7cbdd" "machine"="mhc-ms-fgkll-g6j6c" "namespace"="test-mhc-52lgr" "cause"="cluster is being deleted" "node"=null
I0814 03:08:26.128334   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fzt2s" "namespace"="test-mhc-52lgr" 
I0814 03:08:26.129312   10513 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-7cbdd" "namespace"="test-mhc-52lgr" "descendants"="Machine sets: mhc-ms-fgkll;Worker machines: mhc-ms-fgkll-g6j6c" "indirect descendants count"=1
I0814 03:08:26.134686   10513 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-7cbdd" "namespace"="test-mhc-52lgr" "descendants"="Worker machines: mhc-ms-fgkll-g6j6c" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_a_machine_is_paused
=== RUN   TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created
... skipping 36 lines ...
I0814 03:08:26.358040   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8q2jc" "namespace"="test-mhc-q4rbn" 
I0814 03:08:26.359844   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8q2jc" "namespace"="test-mhc-q4rbn" 
I0814 03:08:26.360732   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8q2jc" "namespace"="test-mhc-q4rbn" 
I0814 03:08:26.362549   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8q2jc" "namespace"="test-mhc-q4rbn" 
I0814 03:08:26.364635   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8q2jc" "namespace"="test-mhc-q4rbn" 
I0814 03:08:26.365663   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8q2jc" "namespace"="test-mhc-q4rbn" 
E0814 03:08:26.365795   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ztb48\" for machine \"test-mhc-machine-k2sfz\" in namespace \"test-mhc-8kdbk\": Cluster.cluster.x-k8s.io \"test-cluster-ztb48\" not found" "controller"="machine" "name"="test-mhc-machine-k2sfz" "namespace"="test-mhc-8kdbk"
node created: test-mhc-node-fjjc4
E0814 03:08:26.379617   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-fjjc4, got []"  "node"="test-mhc-node-fjjc4"
E0814 03:08:26.379666   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-fjjc4, got []"  "node"="test-mhc-node-fjjc4"
E0814 03:08:26.379666   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-fjjc4, got []"  "node"="test-mhc-node-fjjc4"
E0814 03:08:26.383028   10513 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-qnm6m/test-cluster-6pj5j"
I0814 03:08:26.433083   10513 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-ktk27" "target"="test-mhc-q4rbn/test-mhc-8q2jc/test-mhc-machine-ktk27/"
I0814 03:08:26.447740   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8q2jc" "namespace"="test-mhc-q4rbn" 
I0814 03:08:26.478626   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8q2jc" "namespace"="test-mhc-q4rbn" 
I0814 03:08:26.488024   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8q2jc" "namespace"="test-mhc-q4rbn" 
I0814 03:08:26.491803   10513 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-ktk27" "target"="test-mhc-q4rbn/test-mhc-8q2jc/test-mhc-machine-ktk27/test-mhc-node-fjjc4"
I0814 03:08:26.511504   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8q2jc" "namespace"="test-mhc-q4rbn" 
Cleaning up nodes, machines and infra machines.
I0814 03:08:26.521690   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8q2jc" "namespace"="test-mhc-q4rbn" 
I0814 03:08:26.528433   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8q2jc" "namespace"="test-mhc-q4rbn" 
I0814 03:08:26.539344   10513 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-6v8c6" "namespace"="test-mhc-q4rbn" "descendants"="Worker machines: test-mhc-machine-ktk27" "indirect descendants count"=1
I0814 03:08:26.543844   10513 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-6v8c6" "namespace"="test-mhc-q4rbn" "descendants"="Worker machines: test-mhc-machine-ktk27" "indirect descendants count"=1
... skipping 342 lines ...
I0814 03:08:27.387132   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:27.388849   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:27.390603   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:27.393174   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:27.395142   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:27.396977   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
E0814 03:08:27.397778   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-fgkll-g6j6c\" not found" "controller"="machine" "name"="mhc-ms-fgkll-g6j6c" "namespace"="test-mhc-52lgr"
I0814 03:08:27.398728   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:27.400522   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:27.402238   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:27.404108   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:27.405838   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:27.407637   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
... skipping 527 lines ...
I0814 03:08:28.426962   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:28.432580   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:28.434706   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:28.436875   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:28.438739   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:28.440606   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
E0814 03:08:28.442285   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-ktk27\" not found" "controller"="machine" "name"="test-mhc-machine-ktk27" "namespace"="test-mhc-q4rbn"
I0814 03:08:28.442488   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:28.444361   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:28.446287   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:28.447968   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:28.449667   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:28.451778   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
... skipping 488 lines ...
I0814 03:08:29.447216   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:29.449010   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:29.450699   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:29.451336   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:29.452475   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:29.454097   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
E0814 03:08:29.454768   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ztb48\" for machine \"test-mhc-machine-4c5jr\" in namespace \"test-mhc-8kdbk\": Cluster.cluster.x-k8s.io \"test-cluster-ztb48\" not found" "controller"="machine" "name"="test-mhc-machine-4c5jr" "namespace"="test-mhc-8kdbk"
I0814 03:08:29.455316   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:29.460575   10513 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-j9klj" "target"="test-mhc-hn9zv/test-mhc-m4jb4/test-mhc-machine-j9klj/"
I0814 03:08:29.472065   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
E0814 03:08:29.509939   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-xnz92, got []"  "node"="test-mhc-node-xnz92"
E0814 03:08:29.510006   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-xnz92, got []"  "node"="test-mhc-node-xnz92"
E0814 03:08:29.510021   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-xnz92, got []"  "node"="test-mhc-node-xnz92"
node created: test-mhc-node-xnz92
I0814 03:08:29.519721   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:29.542560   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:29.552461   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:29.556974   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:29.561755   10513 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-j9klj" "target"="test-mhc-hn9zv/test-mhc-m4jb4/test-mhc-machine-j9klj/test-mhc-node-xnz92"
I0814 03:08:29.595044   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:29.599214   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:29.624600   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
Cleaning up nodes, machines and infra machines.
I0814 03:08:29.637329   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
I0814 03:08:29.647288   10513 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-j9klj" "target"="test-mhc-hn9zv/test-mhc-m4jb4/test-mhc-machine-j9klj/"
I0814 03:08:29.657846   10513 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-5jqrq" "namespace"="test-mhc-hn9zv" "descendants"="Worker machines: test-mhc-machine-j9klj" "indirect descendants count"=1
I0814 03:08:29.664274   10513 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-5jqrq" "namespace"="test-mhc-hn9zv" "descendants"="Worker machines: test-mhc-machine-j9klj" "indirect descendants count"=1
E0814 03:08:29.671030   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-m4jb4\" not found" "controller"="machinehealthcheck" "name"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv"
--- PASS: TestMachineHealthCheck_Reconcile (41.60s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist (0.05s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value (0.06s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present (0.03s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist (1.05s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones (0.14s)
... skipping 10 lines ...
    --- SKIP: TestMachineHealthCheck_Reconcile/when_a_machine_is_paused (0.00s)
        machinehealthcheck_controller_test.go:933: skipping until made stable
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created (0.41s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (3.12s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0814 03:08:29.674290   10513 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
E0814 03:08:29.675580   10513 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
E0814 03:08:29.677069   10513 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E0814 03:08:29.677331   10513 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
E0814 03:08:29.677677   10513 machinehealthcheck_controller.go:480]  "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node node1, got [machine1 machine2]"  "node"="node1"
=== RUN   TestNodeToMachineHealthCheck/when_no_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_two_MachineHealthChecks_exist_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node,_but_not_in_the_Machine's_cluster
--- PASS: TestNodeToMachineHealthCheck (0.00s)
    --- PASS: TestNodeToMachineHealthCheck/when_the_object_passed_isn't_a_Node (0.00s)
... skipping 31 lines ...
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_nil (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_not_an_int_or_percentage (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_an_int (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_a_40%_(of_5) (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_a_60%_(of_7) (0.00s)
=== RUN   TestPatchTargets
I0814 03:08:29.681008   10513 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0814 03:08:29.681480   10513 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0814 03:08:29.683442   10513 machinehealthcheck_controller.go:320]  "msg"="failed to patch healthy machine status for machine" "error"="machines.cluster.x-k8s.io \"machine1\" not found"  "machine"="machine1"
--- PASS: TestPatchTargets (0.00s)
=== RUN   TestGetTargetsFromMHC
=== RUN   TestGetTargetsFromMHC/with_no_matching_machines
=== RUN   TestGetTargetsFromMHC/when_a_machine's_node_is_missing
=== RUN   TestGetTargetsFromMHC/when_a_machine's_labels_do_not_match_the_selector
=== RUN   TestGetTargetsFromMHC/with_multiple_machines,_should_match_correct_nodes
... skipping 26 lines ...
--- PASS: TestMachineSetOwnerReference (0.00s)
    --- PASS: TestMachineSetOwnerReference/should_add_cluster_owner_reference_to_machine_set (0.00s)
    --- PASS: TestMachineSetOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_deployment (0.00s)
=== RUN   TestMachineSetReconcile
=== RUN   TestMachineSetReconcile/ignore_machine_sets_marked_for_deletion
=== RUN   TestMachineSetReconcile/records_event_if_reconcile_fails
E0814 03:08:29.694517   10513 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
E0814 03:08:29.695913   10513 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 73 lines ...
I0814 03:08:29.973330   10513 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-jvg27-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3
I0814 03:08:29.973397   10513 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-jvg27-6657c7fddb" "namespace"="md-test" 
I0814 03:08:29.990067   10513 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-jvg27-6657c7fddb-qrwxc\"" "machineset"="md-jvg27-6657c7fddb" "namespace"="md-test" 
I0814 03:08:30.076033   10513 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-jvg27-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0814 03:08:30.076073   10513 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-jvg27-cdfc6fd6c" "namespace"="md-test" 
I0814 03:08:30.087160   10513 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-jvg27-cdfc6fd6c-5bk7p\"" "machineset"="md-jvg27-cdfc6fd6c" "namespace"="md-test" 
E0814 03:08:30.173448   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-jvg27-cdfc6fd6c-5bk7p-zkl9l, got []"  "node"="md-jvg27-cdfc6fd6c-5bk7p-zkl9l"
E0814 03:08:30.173582   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-jvg27-cdfc6fd6c-5bk7p-zkl9l, got []"  "node"="md-jvg27-cdfc6fd6c-5bk7p-zkl9l"
E0814 03:08:30.173915   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-jvg27-cdfc6fd6c-5bk7p-zkl9l, got []"  "node"="md-jvg27-cdfc6fd6c-5bk7p-zkl9l"
E0814 03:08:30.279985   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-jvg27-cdfc6fd6c-5bk7p-zkl9l, got []"  "node"="md-jvg27-cdfc6fd6c-5bk7p-zkl9l"
E0814 03:08:30.280054   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-jvg27-cdfc6fd6c-5bk7p-zkl9l, got []"  "node"="md-jvg27-cdfc6fd6c-5bk7p-zkl9l"
E0814 03:08:30.279984   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-jvg27-cdfc6fd6c-5bk7p-zkl9l, got []"  "node"="md-jvg27-cdfc6fd6c-5bk7p-zkl9l"
E0814 03:08:30.280095   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-jvg27-cdfc6fd6c-5bk7p-zkl9l, got []"  "node"="md-jvg27-cdfc6fd6c-5bk7p-zkl9l"
E0814 03:08:30.279991   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-jvg27-cdfc6fd6c-5bk7p-zkl9l, got []"  "node"="md-jvg27-cdfc6fd6c-5bk7p-zkl9l"
E0814 03:08:30.280129   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-jvg27-cdfc6fd6c-5bk7p-zkl9l, got []"  "node"="md-jvg27-cdfc6fd6c-5bk7p-zkl9l"
E0814 03:08:30.316314   10513 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-jvg27-cdfc6fd6c-5bk7p-zkl9l for machine md-test/md-jvg27-cdfc6fd6c-5bk7p: the cache is not started, can not read objects" "machineset"="md-jvg27-cdfc6fd6c" "namespace"="md-test" 
I0814 03:08:30.455477   10513 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-5jqrq" "machine"="test-mhc-machine-j9klj" "namespace"="test-mhc-hn9zv" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-xnz92"}
E0814 03:08:30.490368   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-j9klj\" not found" "controller"="machine" "name"="test-mhc-machine-j9klj" "namespace"="test-mhc-hn9zv"
I0814 03:08:30.671338   10513 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m4jb4" "namespace"="test-mhc-hn9zv" 
E0814 03:08:31.147233   10513 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-52lgr/test-cluster-7cbdd"
E0814 03:08:31.558766   10513 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-q4rbn/test-cluster-6v8c6"
I0814 03:08:31.580377   10513 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-jvg27-6657c7fddb-pzzhj" "namespace"="md-test" 
I0814 03:08:31.580443   10513 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-jvg27-6657c7fddb-pzzhj" "namespace"="md-test" 
I0814 03:08:31.596957   10513 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-jvg27-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0814 03:08:31.597018   10513 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-jvg27-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0814 03:08:31.599065   10513 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-jvg27-6657c7fddb-cg6x6" "namespace"="md-test" 
I0814 03:08:31.599116   10513 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-jvg27-6657c7fddb-cg6x6" "namespace"="md-test" 
... skipping 2 lines ...
I0814 03:08:31.663943   10513 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-jvg27-6657c7fddb-j8z4x" "namespace"="md-test" 
I0814 03:08:31.664030   10513 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-jvg27-6657c7fddb-j8z4x" "namespace"="md-test" 
I0814 03:08:31.687974   10513 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-jvg27-6657c7fddb-qrwxc" "namespace"="md-test" 
I0814 03:08:31.688014   10513 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-jvg27-6657c7fddb-qrwxc" "namespace"="md-test" 
I0814 03:08:31.716542   10513 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-jvg27-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0814 03:08:31.716595   10513 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-jvg27-cdfc6fd6c" "namespace"="md-test" 
E0814 03:08:31.727036   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-jvg27-cdfc6fd6c-5bk7p\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-jvg27-cdfc6fd6c-5bk7p" "namespace"="md-test"
I0814 03:08:31.729791   10513 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-jvg27-cdfc6fd6c-wlng4\"" "machineset"="md-jvg27-cdfc6fd6c" "namespace"="md-test" 
E0814 03:08:31.792101   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-jvg27-cdfc6fd6c-wlng4-gt2sv, got []"  "node"="md-jvg27-cdfc6fd6c-wlng4-gt2sv"
E0814 03:08:31.796117   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-jvg27-cdfc6fd6c-wlng4-gt2sv, got []"  "node"="md-jvg27-cdfc6fd6c-wlng4-gt2sv"
E0814 03:08:31.796186   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-jvg27-cdfc6fd6c-wlng4-gt2sv, got []"  "node"="md-jvg27-cdfc6fd6c-wlng4-gt2sv"
I0814 03:08:31.840610   10513 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-jvg27-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=1
I0814 03:08:31.840650   10513 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-jvg27-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0814 03:08:31.844664   10513 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-jvg27-6657c7fddb" "namespace"="md-test" "machine"="md-jvg27-6657c7fddb-qrwxc"
I0814 03:08:31.957200   10513 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-jvg27-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=3
I0814 03:08:31.957244   10513 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-jvg27-cdfc6fd6c" "namespace"="md-test" 
I0814 03:08:31.970671   10513 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-jvg27-cdfc6fd6c-fdxc8\"" "machineset"="md-jvg27-cdfc6fd6c" "namespace"="md-test" 
E0814 03:08:32.067086   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-jvg27-cdfc6fd6c-fdxc8-gb6v9, got []"  "node"="md-jvg27-cdfc6fd6c-fdxc8-gb6v9"
E0814 03:08:32.170737   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-jvg27-cdfc6fd6c-fdxc8-gb6v9, got []"  "node"="md-jvg27-cdfc6fd6c-fdxc8-gb6v9"
E0814 03:08:32.170780   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-jvg27-cdfc6fd6c-fdxc8-gb6v9, got []"  "node"="md-jvg27-cdfc6fd6c-fdxc8-gb6v9"
I0814 03:08:32.217234   10513 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-jvg27-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=0
I0814 03:08:32.217297   10513 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-jvg27-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0814 03:08:32.221966   10513 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-jvg27-6657c7fddb" "namespace"="md-test" "machine"="md-jvg27-6657c7fddb-j8z4x"
I0814 03:08:32.428094   10513 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-jvg27-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=1
I0814 03:08:32.428139   10513 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-jvg27-74d45c49c5" "namespace"="md-test" 
I0814 03:08:32.438132   10513 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-jvg27-74d45c49c5-rzcx4\"" "machineset"="md-jvg27-74d45c49c5" "namespace"="md-test" 
E0814 03:08:32.524412   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-jvg27-74d45c49c5-rzcx4-j4d8r, got []"  "node"="md-jvg27-74d45c49c5-rzcx4-j4d8r"
E0814 03:08:32.628607   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-jvg27-74d45c49c5-rzcx4-j4d8r, got []"  "node"="md-jvg27-74d45c49c5-rzcx4-j4d8r"
E0814 03:08:32.628650   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-jvg27-74d45c49c5-rzcx4-j4d8r, got []"  "node"="md-jvg27-74d45c49c5-rzcx4-j4d8r"
I0814 03:08:32.673457   10513 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-jvg27-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2
I0814 03:08:32.673518   10513 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-jvg27-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0814 03:08:32.682806   10513 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-jvg27-cdfc6fd6c" "namespace"="md-test" "machine"="md-jvg27-cdfc6fd6c-5bk7p"
I0814 03:08:32.716918   10513 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-jvg27-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=2
I0814 03:08:32.716971   10513 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-jvg27-74d45c49c5" "namespace"="md-test" 
I0814 03:08:32.733536   10513 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-jvg27-74d45c49c5-qr8kc\"" "machineset"="md-jvg27-74d45c49c5" "namespace"="md-test" 
I0814 03:08:32.734215   10513 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-jvg27-6657c7fddb-pzzhj" "namespace"="md-test" 
I0814 03:08:32.734249   10513 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-jvg27-6657c7fddb-pzzhj" "namespace"="md-test" 
I0814 03:08:32.745885   10513 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-jvg27-6657c7fddb-cg6x6" "namespace"="md-test" 
I0814 03:08:32.745942   10513 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-jvg27-6657c7fddb-cg6x6" "namespace"="md-test" 
I0814 03:08:32.746829   10513 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-jvg27-6657c7fddb-knhcs" "namespace"="md-test" "cause"="noderef is nil" "node"=null
E0814 03:08:32.774397   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-jvg27-74d45c49c5-qr8kc-qsqz4, got []"  "node"="md-jvg27-74d45c49c5-qr8kc-qsqz4"
E0814 03:08:32.787155   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-jvg27-74d45c49c5-qr8kc-qsqz4, got []"  "node"="md-jvg27-74d45c49c5-qr8kc-qsqz4"
E0814 03:08:32.787219   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-jvg27-74d45c49c5-qr8kc-qsqz4, got []"  "node"="md-jvg27-74d45c49c5-qr8kc-qsqz4"
E0814 03:08:32.796523   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-jvg27-6657c7fddb-knhcs\" not found" "controller"="machine" "name"="md-jvg27-6657c7fddb-knhcs" "namespace"="md-test"
I0814 03:08:32.858492   10513 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-jvg27-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1
I0814 03:08:32.858543   10513 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-jvg27-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0814 03:08:32.869578   10513 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-jvg27-cdfc6fd6c" "namespace"="md-test" "machine"="md-jvg27-cdfc6fd6c-fdxc8"
I0814 03:08:32.981503   10513 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-jvg27-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0814 03:08:32.981563   10513 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-jvg27-74d45c49c5" "namespace"="md-test" 
I0814 03:08:33.003156   10513 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-jvg27-74d45c49c5-898x9\"" "machineset"="md-jvg27-74d45c49c5" "namespace"="md-test" 
E0814 03:08:33.056121   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-jvg27-74d45c49c5-898x9-hw97r, got []"  "node"="md-jvg27-74d45c49c5-898x9-hw97r"
E0814 03:08:33.159773   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-jvg27-74d45c49c5-898x9-hw97r, got []"  "node"="md-jvg27-74d45c49c5-898x9-hw97r"
E0814 03:08:33.159832   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-jvg27-74d45c49c5-898x9-hw97r, got []"  "node"="md-jvg27-74d45c49c5-898x9-hw97r"
E0814 03:08:33.199232   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinedeployments.cluster.x-k8s.io \"md-jvg27\" not found" "controller"="machinedeployment" "name"="md-jvg27" "namespace"="md-test"
I0814 03:08:33.204605   10513 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-jvg27-74d45c49c5,md-jvg27-cdfc6fd6c;Worker machines: md-jvg27-6657c7fddb-pzzhj,md-jvg27-cdfc6fd6c-5bk7p,md-jvg27-cdfc6fd6c-wlng4,md-jvg27-74d45c49c5-rzcx4,md-jvg27-74d45c49c5-qr8kc,md-jvg27-6657c7fddb-cg6x6,md-jvg27-6657c7fddb-j8z4x,md-jvg27-6657c7fddb-qrwxc,md-jvg27-74d45c49c5-898x9" "indirect descendants count"=11
I0814 03:08:33.206582   10513 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-jvg27-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=0
I0814 03:08:33.206632   10513 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-jvg27-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
•I0814 03:08:33.207859   10513 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"
I0814 03:08:33.208665   10513 machine_controller_phases.go:219]  "msg"="Bootstrap provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0814 03:08:33.208743   10513 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 18 lines ...
I0814 03:08:33.226580   10513 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"
•I0814 03:08:33.228431   10513 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"
I0814 03:08:33.229107   10513 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"
I0814 03:08:33.229782   10513 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0814 03:08:33.229815   10513 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0814 03:08:33.230454   10513 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0814 03:08:33.231735   10513 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" 
•I0814 03:08:33.361220   10513 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-46nwf" "namespace"="ms-test" "creating"=2 "need"=2
I0814 03:08:33.361262   10513 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-46nwf" "namespace"="ms-test" 
I0814 03:08:33.380034   10513 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-46nwf-48nkh\"" "machineset"="ms-46nwf" "namespace"="ms-test" 
I0814 03:08:33.380093   10513 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-46nwf" "namespace"="ms-test" 
I0814 03:08:33.400663   10513 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-46nwf-42zb4\"" "machineset"="ms-46nwf" "namespace"="ms-test" 
I0814 03:08:33.507332   10513 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-46nwf" "namespace"="ms-test" "creating"=1 "need"=2
I0814 03:08:33.507381   10513 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-46nwf" "namespace"="ms-test" 
I0814 03:08:33.529692   10513 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-46nwf-npx2z\"" "machineset"="ms-46nwf" "namespace"="ms-test" 
E0814 03:08:33.617777   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-46nwf-npx2z-hp5d8, got []"  "node"="ms-46nwf-npx2z-hp5d8"
E0814 03:08:33.722444   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-46nwf-npx2z-hp5d8, got []"  "node"="ms-46nwf-npx2z-hp5d8"
E0814 03:08:33.722511   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-46nwf-npx2z-hp5d8, got []"  "node"="ms-46nwf-npx2z-hp5d8"
E0814 03:08:33.767540   10513 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-46nwf-npx2z-hp5d8 for machine ms-test/ms-46nwf-npx2z: the cache is not started, can not read objects" "machineset"="ms-46nwf" "namespace"="ms-test" 
E0814 03:08:33.776105   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-46nwf-42zb4-zxrkd, got []"  "node"="ms-46nwf-42zb4-zxrkd"
E0814 03:08:33.781697   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-46nwf-42zb4-zxrkd, got []"  "node"="ms-46nwf-42zb4-zxrkd"
E0814 03:08:33.781760   10513 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-46nwf-42zb4-zxrkd, got []"  "node"="ms-46nwf-42zb4-zxrkd"
I0814 03:08:33.797445   10513 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-jvg27-6657c7fddb-j8z4x" "namespace"="md-test" "cause"="cluster is being deleted" "node"=null
I0814 03:08:33.837268   10513 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-jvg27-6657c7fddb-qrwxc" "namespace"="md-test" "cause"="cluster is being deleted" "node"=null
I0814 03:08:33.874149   10513 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-jvg27-cdfc6fd6c-5bk7p" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-jvg27-cdfc6fd6c-5bk7p-zkl9l"}
I0814 03:08:33.915076   10513 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-46nwf-npx2z,ms-46nwf-42zb4" "indirect descendants count"=2
•I0814 03:08:33.925605   10513 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-46nwf-npx2z,ms-46nwf-42zb4" "indirect descendants count"=2
I0814 03:08:33.983819   10513 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-jvg27-6657c7fddb-cg6x6" "namespace"="md-test" 
I0814 03:08:33.983884   10513 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-jvg27-6657c7fddb-cg6x6" "namespace"="md-test" 
I0814 03:08:33.989990   10513 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-jvg27-6657c7fddb-pzzhj" "namespace"="md-test" 
I0814 03:08:33.990055   10513 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-jvg27-6657c7fddb-pzzhj" "namespace"="md-test" 
I0814 03:08:34.026588   10513 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-jvg27-6657c7fddb-j8z4x" "namespace"="md-test" "cause"="cluster is being deleted" "node"=null
•E0814 03:08:34.064800   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-5jgf9\" not found" "controller"="cluster" "name"="test1-5jgf9" "namespace"="default"
E0814 03:08:34.066723   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-jvg27-6657c7fddb-j8z4x\" not found" "controller"="machine" "name"="md-jvg27-6657c7fddb-j8z4x" "namespace"="md-test"
I0814 03:08:35.067246   10513 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-jvg27-6657c7fddb-qrwxc" "namespace"="md-test" "cause"="cluster is being deleted" "node"=null
E0814 03:08:35.086975   10513 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-hn9zv/test-cluster-5jqrq"
E0814 03:08:35.098473   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-jvg27-6657c7fddb-qrwxc\" not found" "controller"="machine" "name"="md-jvg27-6657c7fddb-qrwxc" "namespace"="md-test"
•I0814 03:08:35.210216   10513 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-t8h99" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0814 03:08:35.328690   10513 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-t8h99" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0814 03:08:35.333937   10513 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-t8h99" "namespace"="default"
I0814 03:08:36.099327   10513 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-jvg27-cdfc6fd6c-5bk7p" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-jvg27-cdfc6fd6c-5bk7p-zkl9l"}
E0814 03:08:36.125544   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-jvg27-cdfc6fd6c-5bk7p\" not found" "controller"="machine" "name"="md-jvg27-cdfc6fd6c-5bk7p" "namespace"="md-test"
E0814 03:08:36.353135   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-t8h99: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-t8h99" "namespace"="default"
•E0814 03:08:37.153526   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-jvg27-74d45c49c5-rzcx4\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-jvg27-74d45c49c5-rzcx4" "namespace"="md-test"
E0814 03:08:37.370716   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-xwnrb\" not found" "controller"="cluster" "name"="test3-xwnrb" "namespace"="default"
E0814 03:08:38.182784   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-jvg27-74d45c49c5-qr8kc\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-jvg27-74d45c49c5-qr8kc" "namespace"="md-test"
E0814 03:08:38.371497   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-t8h99: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-t8h99" "namespace"="default"
I0814 03:08:39.329212   10513 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-jvg27-6657c7fddb-cg6x6" "namespace"="md-test" 
I0814 03:08:39.329461   10513 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-jvg27-6657c7fddb-cg6x6" "namespace"="md-test" 
I0814 03:08:39.338307   10513 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-jvg27-6657c7fddb-pzzhj" "namespace"="md-test" 
I0814 03:08:39.338364   10513 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-jvg27-6657c7fddb-pzzhj" "namespace"="md-test" 
E0814 03:08:39.338986   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ztb48\" for machine \"test-mhc-machine-k2sfz\" in namespace \"test-mhc-8kdbk\": Cluster.cluster.x-k8s.io \"test-cluster-ztb48\" not found" "controller"="machine" "name"="test-mhc-machine-k2sfz" "namespace"="test-mhc-8kdbk"
I0814 03:08:39.384440   10513 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-jvg27-74d45c49c5,md-jvg27-cdfc6fd6c;Worker machines: md-jvg27-6657c7fddb-pzzhj,md-jvg27-6657c7fddb-cg6x6,md-jvg27-74d45c49c5-rzcx4,md-jvg27-74d45c49c5-qr8kc,md-jvg27-74d45c49c5-898x9" "indirect descendants count"=7
E0814 03:08:39.388377   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-t8h99: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-t8h99" "namespace"="default"
•E0814 03:08:40.345624   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-jvg27-74d45c49c5-rzcx4\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-jvg27-74d45c49c5-rzcx4" "namespace"="md-test"
I0814 03:08:40.389117   10513 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-46nwf-npx2z,ms-46nwf-42zb4" "indirect descendants count"=2
E0814 03:08:40.394345   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-lqkw6: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-lqkw6" "namespace"="default"
E0814 03:08:41.351451   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-jvg27-74d45c49c5-qr8kc\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-jvg27-74d45c49c5-qr8kc" "namespace"="md-test"
E0814 03:08:41.395129   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-t8h99: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-t8h99" "namespace"="default"
E0814 03:08:42.380530   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ztb48\" for machine \"test-mhc-machine-4c5jr\" in namespace \"test-mhc-8kdbk\": Cluster.cluster.x-k8s.io \"test-cluster-ztb48\" not found" "controller"="machine" "name"="test-mhc-machine-4c5jr" "namespace"="test-mhc-8kdbk"
E0814 03:08:42.405389   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-lqkw6: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-lqkw6" "namespace"="default"
•I0814 03:08:43.386073   10513 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-jvg27-6657c7fddb-cg6x6" "namespace"="md-test" 
I0814 03:08:43.386120   10513 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-jvg27-6657c7fddb-cg6x6" "namespace"="md-test" 
I0814 03:08:43.390771   10513 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-jvg27-6657c7fddb-pzzhj" "namespace"="md-test" 
I0814 03:08:43.390819   10513 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-jvg27-6657c7fddb-pzzhj" "namespace"="md-test" 
E0814 03:08:43.395493   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-jvg27-74d45c49c5-rzcx4\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-jvg27-74d45c49c5-rzcx4" "namespace"="md-test"
E0814 03:08:43.406195   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-t8h99: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-t8h99" "namespace"="default"
E0814 03:08:44.400700   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-jvg27-74d45c49c5-qr8kc\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-jvg27-74d45c49c5-qr8kc" "namespace"="md-test"
E0814 03:08:44.406930   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-lqkw6: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-lqkw6" "namespace"="default"
E0814 03:08:45.415793   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-jvg27-74d45c49c5-rzcx4\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-jvg27-74d45c49c5-rzcx4" "namespace"="md-test"
E0814 03:08:45.417074   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-t8h99: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-t8h99" "namespace"="default"
I0814 03:08:46.417688   10513 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-jvg27-74d45c49c5,md-jvg27-cdfc6fd6c;Worker machines: md-jvg27-6657c7fddb-pzzhj,md-jvg27-6657c7fddb-cg6x6,md-jvg27-74d45c49c5-rzcx4,md-jvg27-74d45c49c5-qr8kc,md-jvg27-74d45c49c5-898x9" "indirect descendants count"=7
E0814 03:08:46.418132   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-lqkw6: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-lqkw6" "namespace"="default"
I0814 03:08:46.420284   10513 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-jvg27-6657c7fddb-cg6x6" "namespace"="md-test" 
I0814 03:08:46.420318   10513 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-jvg27-6657c7fddb-cg6x6" "namespace"="md-test" 
I0814 03:08:46.423824   10513 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-jvg27-6657c7fddb-pzzhj" "namespace"="md-test" 
I0814 03:08:46.423858   10513 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-jvg27-6657c7fddb-pzzhj" "namespace"="md-test" 
E0814 03:08:46.428010   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-jvg27-74d45c49c5-qr8kc\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-jvg27-74d45c49c5-qr8kc" "namespace"="md-test"
I0814 03:08:47.418890   10513 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-46nwf-npx2z,ms-46nwf-42zb4" "indirect descendants count"=2
E0814 03:08:47.419774   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-t8h99: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-t8h99" "namespace"="default"
E0814 03:08:47.433378   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-jvg27-74d45c49c5-rzcx4\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-jvg27-74d45c49c5-rzcx4" "namespace"="md-test"
E0814 03:08:48.420742   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-lqkw6: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-lqkw6" "namespace"="default"
E0814 03:08:48.449867   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-jvg27-74d45c49c5-qr8kc\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-jvg27-74d45c49c5-qr8kc" "namespace"="md-test"
E0814 03:08:49.421712   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-t8h99: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-t8h99" "namespace"="default"
I0814 03:08:49.456237   10513 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-jvg27-6657c7fddb-cg6x6" "namespace"="md-test" 
I0814 03:08:49.456292   10513 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-jvg27-6657c7fddb-cg6x6" "namespace"="md-test" 
I0814 03:08:49.461463   10513 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-jvg27-6657c7fddb-pzzhj" "namespace"="md-test" 
I0814 03:08:49.461510   10513 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-jvg27-6657c7fddb-pzzhj" "namespace"="md-test" 
E0814 03:08:49.467201   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-jvg27-74d45c49c5-rzcx4\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-jvg27-74d45c49c5-rzcx4" "namespace"="md-test"
E0814 03:08:50.422699   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-lqkw6: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-lqkw6" "namespace"="default"
I0814 03:08:50.486985   10513 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-5p82p" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0814 03:08:50.500604   10513 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-5p82p" "namespace"="default" 
E0814 03:08:50.523265   10513 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-5p82p" "namespace"="default"
E0814 03:08:51.423611   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-lqkw6: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-lqkw6" "namespace"="default"
E0814 03:08:51.529497   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-jvg27-74d45c49c5-qr8kc\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-jvg27-74d45c49c5-qr8kc" "namespace"="md-test"
E0814 03:08:52.424421   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-t8h99: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-t8h99" "namespace"="default"
E0814 03:08:52.534710   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-jvg27-74d45c49c5-rzcx4\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-jvg27-74d45c49c5-rzcx4" "namespace"="md-test"
I0814 03:08:53.425151   10513 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-jvg27-74d45c49c5,md-jvg27-cdfc6fd6c;Worker machines: md-jvg27-6657c7fddb-cg6x6,md-jvg27-74d45c49c5-rzcx4,md-jvg27-74d45c49c5-qr8kc,md-jvg27-74d45c49c5-898x9,md-jvg27-6657c7fddb-pzzhj" "indirect descendants count"=7
E0814 03:08:53.425811   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-lqkw6: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-lqkw6" "namespace"="default"
I0814 03:08:53.539541   10513 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-jvg27-6657c7fddb-cg6x6" "namespace"="md-test" 
I0814 03:08:53.539588   10513 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-jvg27-6657c7fddb-cg6x6" "namespace"="md-test" 
I0814 03:08:53.545171   10513 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-jvg27-6657c7fddb-pzzhj" "namespace"="md-test" 
I0814 03:08:53.545228   10513 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-jvg27-6657c7fddb-pzzhj" "namespace"="md-test" 
I0814 03:08:53.560975   10513 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-5p82p" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0814 03:08:53.561215   10513 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-5p82p" "namespace"="default" "noderef"="id-node-1"
E0814 03:08:53.576768   10513 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-5p82p" "namespace"="default"
I0814 03:08:54.426578   10513 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-46nwf-npx2z,ms-46nwf-42zb4" "indirect descendants count"=2
E0814 03:08:54.431399   10513 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-lqkw6: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-lqkw6" "namespace"="default"

------------------------------
• [SLOW TEST:12.069 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
  /home/prow/go/src/sigs.k8s.io/cluster-api/controllers/cluster_controller_test.go:248
------------------------------


Ran 16 of 16 Specs in 24.835 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (24.83s)
PASS
Tearing down test suite
E0814 03:08:54.532539   10513 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0814 03:08:54.532610   10513 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-255047721/tls.crt: no such file or directory"  
E0814 03:08:54.532632   10513 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0814 03:08:54.532650   10513 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-255047721/tls.crt: no such file or directory"  
I0814 03:08:54.532713   10513 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I0814 03:08:54.532796   10513 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0814 03:08:54.532863   10513 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0814 03:08:54.532887   10513 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0814 03:08:54.532965   10513 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
I0814 03:08:54.532991   10513 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
I0814 03:08:54.533011   10513 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
E0814 03:08:54.565735   10513 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:35637/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1338&timeout=10s&timeoutSeconds=354&watch=true: dial tcp 127.0.0.1:35637: connect: connection refused
W0814 03:08:54.565732   10513 reflector.go:328] pkg/mod/k8s.io/client-go@v0.17.9/tools/cache/reflector.go:105: watch of *v1.Node ended with: very short watch: pkg/mod/k8s.io/client-go@v0.17.9/tools/cache/reflector.go:105: Unexpected watch close - watch lasted less than a second and no items received
E0814 03:08:54.565813   10513 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:35637/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1338&timeout=10s&timeoutSeconds=428&watch=true: dial tcp 127.0.0.1:35637: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	85.613s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 265 lines ...
I0814 03:07:43.427453   10943 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0814 03:07:43.869573   10943 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0814 03:07:43.886943   10943 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}}}
I0814 03:07:43.987400   10943 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="cluster" 
I0814 03:07:43.987470   10943 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
•I0814 03:07:44.153904   10943 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
E0814 03:07:46.193208   10943 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-dbm7x/test-cluster"
•E0814 03:07:46.683199   10943 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-ncwpp/test-cluster"
•E0814 03:07:47.236767   10943 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:40307/?timeout=50ms: dial tcp 127.0.0.1:40307: connect: connection refused"  "cluster"="cluster-cache-test-qn7cq/test-cluster"
•E0814 03:07:47.446069   10943 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
I0814 03:07:47.446090   10943 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0814 03:07:47.446144   10943 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-144422690/tls.crt: no such file or directory"  
E0814 03:07:47.489192   10943 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:37533/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=146&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:37533: connect: connection refused


Ran 5 of 5 Specs in 16.600 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (16.60s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	16.756s
?   	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
I0814 03:07:55.612432   11564 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
E0814 03:07:55.613750   11564 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
I0814 03:07:55.614423   11564 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I0814 03:07:55.614588   11564 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcilePaused (0.00s)
=== RUN   TestReconcileClusterNoEndpoints
... skipping 192 lines ...
    --- PASS: TestSelectMachineForScaleDown/when_there_is_an_up_to_date_machine_with_delete_annotation,_while_there_are_any_outdated_machines_without_annotatio_that_still_exist,_it_returns_oldest_marked_machine_first (0.00s)
=== RUN   TestPreflightChecks
=== RUN   TestPreflightChecks/control_plane_without_machines_(not_initialized)_should_pass
=== RUN   TestPreflightChecks/control_plane_with_a_deleting_machine_should_requeue
I0814 03:08:14.905362   11564 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
I0814 03:08:14.905627   11564 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: 1660446462
Will run 1 of 1 specs

E0814 03:08:14.926363   11564 controller.go:126]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="Cluster.cluster.x-k8s.io \"kcp-foo-lnmjrr\" not found" "kubeadmControlPlane"="kcp-foo-lnmjrr" "namespace"="test" 
•

Ran 1 of 1 Specs in 0.017 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (0.02s)
=== RUN   TestKubeadmControlPlaneReconciler_upgradeControlPlane
I0814 03:08:14.928190   11564 controller.go:246]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-idz3ad" "kubeadmControlPlane"="kcp-foo-idz3ad" "namespace"="test" 
I0814 03:08:16.388777   11564 controller.go:331]  "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-idz3ad" "kubeadmControlPlane"="kcp-foo-idz3ad" "namespace"="test" "needRollout"=["kcp-foo-idz3ad-skj79"]
I0814 03:08:16.389046   11564 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-idz3ad" "kubeadmControlPlane"="kcp-foo-idz3ad" "namespace"="test" "failures"="[machine kcp-foo-idz3ad-8g7z2 does not have APIServerPodHealthy condition, machine kcp-foo-idz3ad-8g7z2 does not have ControllerManagerPodHealthy condition, machine kcp-foo-idz3ad-8g7z2 does not have SchedulerPodHealthy condition, machine kcp-foo-idz3ad-8g7z2 does not have EtcdPodHealthy condition, machine kcp-foo-idz3ad-8g7z2 does not have EtcdMemberHealthy condition]"
--- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (1.46s)
PASS
I0814 03:08:16.390100   11564 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0814 03:08:16.390301   11564 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0814 03:08:16.390365   11564 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-582820854/tls.crt: no such file or directory"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers	34.362s
I0814 03:07:54.942395   11535 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"
I0814 03:07:54.942519   11535 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster"
I0814 03:07:54.942548   11535 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"
I0814 03:07:54.942570   11535 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster"
I0814 03:07:54.942653   11535 webhook.go:102] controller-runtime/builder "msg"="Registering a mutating webhook"  "GVK"={"Group":"cluster.x-k8s.io","Version":"v1alpha3","Kind":"Machine"} "path"="/mutate-cluster-x-k8s-io-v1alpha3-machine"
... skipping 52 lines ...
==================================
Random Seed: 1660446461
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: 1660446461
Will run 7 of 7 specs

•••••••
Ran 7 of 7 Specs in 0.000 seconds
SUCCESS! -- 7 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestMachineCollection (0.00s)
=== RUN   TestUpdateEtcdConditions
=== RUN   TestUpdateEtcdConditions/if_list_nodes_return_an_error_should_report_all_the_conditions_Unknown
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_be_ignored_if_there_are_provisioning_machines
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_report_a_problem_at_KCP_level_if_there_are_no_provisioning_machines
=== RUN   TestUpdateEtcdConditions/failure_creating_the_etcd_client_should_report_unknown_condition
... skipping 297 lines ...
    --- PASS: TestUpdateKubeProxyImageInfo/returns_error_if_image_repository_is_invalid (0.00s)
    --- PASS: TestUpdateKubeProxyImageInfo/does_not_update_image_repository_when_no_kube-proxy_update_is_requested (0.00s)
=== RUN   TestRemoveMachineFromKubeadmConfigMap
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_find_kubeadm-config_for_Kubernetes_version_<_1.22.0
E0814 03:07:58.882118   11535 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"  
E0814 03:08:07.206403   11535 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"  
E0814 03:08:16.192428   11535 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"  
E0814 03:08:27.322718   11535 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"  
E0814 03:08:43.795984   11535 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"  
E0814 03:08:56.804586   11535 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"  
E0814 03:09:14.452043   11535 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"  
E0814 03:09:35.375545   11535 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"  
E0814 03:10:06.392185   11535 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"  
E0814 03:10:51.549373   11535 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
E0814 03:10:51.558907   11535 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0814 03:10:51.558951   11535 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-063085473/tls.crt: no such file or directory"  
I0814 03:10:51.558991   11535 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0814 03:10:51.559083   11535 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0814 03:10:51.559121   11535 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-063085473/tls.crt: no such file or directory"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/internal	190.037s
=== RUN   TestEtcdMembers_WithErrors
--- PASS: TestEtcdMembers_WithErrors (0.00s)
=== RUN   TestEtcdMembers_WithSuccess
--- PASS: TestEtcdMembers_WithSuccess (0.00s)
PASS
... skipping 287 lines ...
I0814 03:08:05.314419   11846 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0814 03:08:05.314588   11846 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"ConfigMap","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0814 03:08:05.421336   11846 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0814 03:08:05.522897   11846 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0814 03:08:05.522984   11846 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0814 03:08:05.615886   11846 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-74w0za"} 
•E0814 03:08:05.667573   11846 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"
I0814 03:08:06.735229   11846 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-a4cn82"} 
E0814 03:08:06.769241   11846 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"
•E0814 03:08:17.885794   11846 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"

------------------------------
• Failure [11.117 seconds]
ClusterResourceSet Reconciler
/home/prow/go/src/sigs.k8s.io/cluster-api/exp/addons/controllers/clusterresourceset_controller_test.go:40
  Should reconcile a ClusterResourceSet when a resource is created that is part of ClusterResourceSet resources [It]
... skipping 8 lines ...
------------------------------
STEP: Creating the Cluster
STEP: Creating the remote Cluster kubeconfig
STEP: Creating a Secret and a ConfigMap with ConfigMap in their data field
STEP: Verifying ClusterResourceSetBinding is created with cluster owner reference
STEP: Deleting the Kubeconfigsecret
E0814 03:08:19.084652   11846 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"
•E0814 03:08:20.108031   11846 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"
E0814 03:08:21.131244   11846 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"
•I0814 03:08:21.132721   11846 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 
I0814 03:08:21.132808   11846 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
I0814 03:08:21.132874   11846 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  



Summarizing 1 Failure:

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

Ran 5 of 5 Specs in 29.483 seconds
FAIL! -- 4 Passed | 1 Failed | 0 Pending | 0 Skipped
--- FAIL: TestAPIs (29.48s)
FAIL
FAIL	sigs.k8s.io/cluster-api/exp/addons/controllers	29.634s
?   	sigs.k8s.io/cluster-api/exp/addons/controllers/predicates	[no test files]
=== RUN   TestMachinePoolDefault
=== RUN   TestMachinePoolDefault/for_MachinePool
=== RUN   TestMachinePoolDefault/for_MachinePool/validate-on-create
=== RUN   TestMachinePoolDefault/for_MachinePool/validate-on-update
=== RUN   TestMachinePoolDefault/for_MachinePool/validate-on-delete
... skipping 58 lines ...
    --- PASS: TestReconcileMachinePoolBootstrap/new_machinepool,_no_bootstrap_config_or_data (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_data_should_not_change (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_provider_is_to_not_ready (0.00s)
=== RUN   TestReconcileMachinePoolInfrastructure
=== RUN   TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready
=== RUN   TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed
E0814 03:07:56.075764   12023 machinepool_controller_phases.go:237]  "msg"="MachinePool infrastructure reference has been deleted after being ready, setting failure state" "error"="could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureConfig \"infra-config1\" for MachinePool \"machinepool-test\" in namespace \"default\", requeuing: failed to retrieve InfrastructureConfig external object \"default\"/\"infra-config1\": infrastructureconfigs.infrastructure.cluster.x-k8s.io \"infra-config1\" not found" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
=== RUN   TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused
--- PASS: TestReconcileMachinePoolInfrastructure (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestMachinePoolFinalizer
... skipping 95 lines ...
•I0814 03:08:09.378106   12023 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0814 03:08:09.401696   12023 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••I0814 03:08:09.404918   12023 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 9 of 9 Specs in 13.205 seconds
SUCCESS! -- 9 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (13.21s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/controllers	13.532s
?   	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 200 lines ...
I0814 03:08:33.813832   15040 webhook.go:123] controller-runtime/builder "msg"="Registering a validating webhook"  "GVK"={"Group":"addons.cluster.x-k8s.io","Version":"v1alpha3","Kind":"ClusterResourceSet"} "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0814 03:08:33.813871   15040 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0814 03:08:33.814241   15040 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0814 03:08:33.815081   15040 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0814 03:08:33.815284   15040 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=45815
I0814 03:08:33.815414   15040 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
••••••••••••••E0814 03:08:34.783236   15040 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
I0814 03:08:34.783281   15040 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0814 03:08:34.783297   15040 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-229341775/tls.crt: no such file or directory"  


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