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

No Test Failures!


Error lines from build-log.txt

... skipping 777 lines ...
I0619 14:46:09.107774    8445 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0619 14:46:09.697440    8445 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" 
•I0619 14:46:09.716511    8445 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


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	50.307s
=== 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 1407 lines ...
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_error_if_unable_to_reconcile_infrastructure_ref
I0619 14:45:51.134688   10746 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"
I0619 14:45:51.137926   10746 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
I0619 14:45:51.138384   10746 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
2022/06/19 14:45:51 http: TLS handshake error from 127.0.0.1:47606: EOF
I0619 14:45:51.140346   10746 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
I0619 14:45:51.142024   10746 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test-cluster" "namespace"="test-namespace" "err"="cannot create a metadata client without a rest config"
=== RUN   TestClusterReconcilePhases/reconcile_kubeconfig
=== RUN   TestClusterReconcilePhases/reconcile_kubeconfig/cluster_not_provisioned,_apiEndpoint_is_not_set
=== RUN   TestClusterReconcilePhases/reconcile_kubeconfig/kubeconfig_secret_found
... skipping 96 lines ...
    --- PASS: TestReconcileBootstrap/existing_machine,_machineset_owner_and_version_v1alpha2,_and_ownerref_updated (0.00s)
=== RUN   TestReconcileInfrastructure
=== RUN   TestReconcileInfrastructure/new_machine,_infrastructure_config_ready
I0619 14:45:51.166693   10746 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
I0619 14:45:51.168223   10746 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"
E0619 14:45:51.168502   10746 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
I0619 14:45:51.168894   10746 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
--- PASS: TestReconcileInfrastructure (0.00s)
    --- PASS: TestReconcileInfrastructure/new_machine,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machine_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestWatches
I0619 14:45:51.477821   10746 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0619 14:45:51.479923   10746 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0619 14:45:51.487671   10746 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-z965p" "namespace"="test-machine-watches-2mklb" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0619 14:45:51.487747   10746 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0619 14:45:51.597073   10746 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-z965p" "namespace"="test-machine-watches-2mklb" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0619 14:45:51.597157   10746 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0619 14:45:51.697690   10746 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-z965p" "namespace"="test-machine-watches-2mklb" "noderef"="node-1"
E0619 14:45:51.704908   10746 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0619 14:45:51.704960   10746 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0619 14:45:51.744087   10746 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-z965p\" in namespace \"test-machine-watches-2mklb\", requeuing: requeue in 1s"  
E0619 14:45:51.753820   10746 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-z965p\" in namespace \"test-machine-watches-2mklb\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-z965p\" in namespace \"test-machine-watches-2mklb\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-z965p" "namespace"="test-machine-watches-2mklb"
--- PASS: TestWatches (0.61s)
=== 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
I0619 14:45:51.966293   10746 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-w9q2m" "namespace"="test-machine-watches-2mklb" "count"=1
I0619 14:45:51.966354   10746 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-w9q2m" "namespace"="test-machine-watches-2mklb" "descendants"="Worker machines: machine-created-z965p" "indirect descendants count"=0
I0619 14:45:51.987707   10746 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-w9q2m" "namespace"="test-machine-watches-2mklb" "count"=1
I0619 14:45:51.987771   10746 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-w9q2m" "namespace"="test-machine-watches-2mklb" "descendants"="Worker machines: machine-created-z965p" "indirect descendants count"=0
I0619 14:45:52.754361   10746 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-w9q2m" "machine"="machine-created-z965p" "namespace"="test-machine-watches-2mklb" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"811000cb-804c-448e-a571-5c8064381cce","apiVersion":"v1"}
E0619 14:45:52.802120   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-z965p\" not found" "controller"="machine" "name"="machine-created-z965p" "namespace"="test-machine-watches-2mklb"
E0619 14:45:53.881450   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-xmrfp\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-cspzd\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-cspzd: secrets \"machine-reconcile-cspzd-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-xmrfp" "namespace"="default"
I0619 14:45:54.881940   10746 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-cspzd" "machine"="machine-created-xmrfp" "namespace"="default" "cause"="noderef is nil" "node"=null
I0619 14:45:54.915033   10746 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-cspzd" "machine"="machine-created-xmrfp" "namespace"="default" "cause"="noderef is nil" "node"=null
I0619 14:45:54.934457   10746 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-cspzd" "machine"="machine-created-xmrfp" "namespace"="default" "cause"="noderef is nil" "node"=null
E0619 14:45:54.961415   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-xmrfp\" not found" "controller"="machine" "name"="machine-created-xmrfp" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.19s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.19s)
=== RUN   TestMachineFinalizer
=== RUN   TestMachineFinalizer/should_add_a_machine_finalizer_to_the_machine_if_it_doesn't_have_one
=== RUN   TestMachineFinalizer/should_append_the_machine_finalizer_to_the_machine_if_it_already_has_a_finalizer
--- PASS: TestMachineFinalizer (0.00s)
... skipping 15 lines ...
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner (0.00s)
=== RUN   TestReconcileRequest
=== RUN   TestReconcileRequest/machine_should_be_created
I0619 14:45:54.987706   10746 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="created" "namespace"="default" "err"="cannot create a metadata client without a rest config"
=== RUN   TestReconcileRequest/machine_should_be_updated
I0619 14:45:54.992493   10746 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="updated" "namespace"="default" "err"="cannot create a metadata client without a rest config"
E0619 14:45:55.002870   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-cspzd\" not found" "controller"="cluster" "name"="machine-reconcile-cspzd" "namespace"="default"
=== RUN   TestReconcileRequest/machine_should_be_deleted
I0619 14:45:55.035007   10746 machine_controller.go:305]  "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="deleted" "namespace"="default" "cause"="noderef is nil" "node"=null
--- PASS: TestReconcileRequest (0.05s)
    --- PASS: TestReconcileRequest/machine_should_be_created (0.00s)
    --- PASS: TestReconcileRequest/machine_should_be_updated (0.02s)
    --- PASS: TestReconcileRequest/machine_should_be_deleted (0.01s)
... skipping 109 lines ...
    --- PASS: TestMachineDeploymentSyncStatus/scaling_up (0.00s)
    --- PASS: TestMachineDeploymentSyncStatus/scaling_down (0.00s)
=== RUN   TestMachineHealthCheck_Reconcile
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist
I0619 14:45:55.182271   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5mv6m" "namespace"="test-mhc-rggbb" 
I0619 14:45:55.199810   10746 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0619 14:45:55.200853   10746 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-svhf2\" not found"  "cluster"="test-mhc-rggbb/test-cluster-svhf2"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
E0619 14:45:55.210901   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-5mv6m\" not found" "controller"="machinehealthcheck" "name"="test-mhc-5mv6m" "namespace"="test-mhc-rggbb"
=== 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
error cannot retrieve mhc in ctx: MachineHealthCheck.cluster.x-k8s.io "test-mhc-t9psz" not foundI0619 14:45:56.211228   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-5mv6m" "namespace"="test-mhc-rggbb" 
I0619 14:45:56.211343   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vck7l" "namespace"="test-mhc-2lxjc" 
I0619 14:45:56.211382   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dqrtb" "namespace"="test-mhc-fcm7s" 
I0619 14:45:56.211417   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t9psz" "namespace"="test-mhc-qtf6k" 
I0619 14:45:56.247430   10746 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0619 14:45:56.364936   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t9psz" "namespace"="test-mhc-qtf6k" 
I0619 14:45:56.370811   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t9psz" "namespace"="test-mhc-qtf6k" 
I0619 14:45:56.410449   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t9psz" "namespace"="test-mhc-qtf6k" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
I0619 14:45:56.435419   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ggld4" "namespace"="test-mhc-t4w4n" 
E0619 14:45:56.438806   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-dlqhh\" not found" "controller"="cluster" "name"="test-cluster-dlqhh" "namespace"="test-mhc-qtf6k"
I0619 14:45:56.453643   10746 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0619 14:45:56.555318   10746 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-qtf6k/test-cluster-dlqhh"
I0619 14:45:56.572348   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ggld4" "namespace"="test-mhc-t4w4n" 
E0619 14:45:56.646657   10746 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-t4w4n/test-cluster-rfshn"
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0619 14:45:56.652898   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ggld4" "namespace"="test-mhc-t4w4n" 
I0619 14:45:56.772826   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9p8nn" "namespace"="test-mhc-g6zxf" 
inframachine created: test-mhc-machine-infra-sqgv4
machine created: test-mhc-machine-q5k2l
I0619 14:45:56.838332   10746 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
... skipping 3 lines ...
I0619 14:45:56.899037   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9p8nn" "namespace"="test-mhc-g6zxf" 
I0619 14:45:56.900739   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9p8nn" "namespace"="test-mhc-g6zxf" 
I0619 14:45:56.902442   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9p8nn" "namespace"="test-mhc-g6zxf" 
I0619 14:45:56.904122   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9p8nn" "namespace"="test-mhc-g6zxf" 
I0619 14:45:56.905811   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9p8nn" "namespace"="test-mhc-g6zxf" 
I0619 14:45:56.907070   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9p8nn" "namespace"="test-mhc-g6zxf" 
I0619 14:45:56.907308   10746 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-g6zxf/test-mhc-9p8nn/test-mhc-machine-q5k2l/"
E0619 14:45:56.944049   10746 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-2rzgf"
node created: test-mhc-node-2rzgf
E0619 14:45:56.944843   10746 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-2rzgf, got []"  "node"="test-mhc-node-2rzgf"
I0619 14:45:56.945353   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9p8nn" "namespace"="test-mhc-g6zxf" 
I0619 14:45:56.945629   10746 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-g6zxf/test-mhc-9p8nn/test-mhc-machine-q5k2l/"
I0619 14:45:56.955303   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9p8nn" "namespace"="test-mhc-g6zxf" 
inframachine created: test-mhc-machine-infra-xfm8f
I0619 14:45:56.973999   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9p8nn" "namespace"="test-mhc-g6zxf" 
machine created: test-mhc-machine-cpb29
I0619 14:45:56.979240   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9p8nn" "namespace"="test-mhc-g6zxf" 
I0619 14:45:56.984358   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9p8nn" "namespace"="test-mhc-g6zxf" 
... skipping 55 lines ...
I0619 14:45:57.119662   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9p8nn" "namespace"="test-mhc-g6zxf" 
I0619 14:45:57.123615   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9p8nn" "namespace"="test-mhc-g6zxf" 
I0619 14:45:57.126313   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9p8nn" "namespace"="test-mhc-g6zxf" 
I0619 14:45:57.129384   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9p8nn" "namespace"="test-mhc-g6zxf" 
I0619 14:45:57.132750   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9p8nn" "namespace"="test-mhc-g6zxf" 
I0619 14:45:57.135914   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9p8nn" "namespace"="test-mhc-g6zxf" 
I0619 14:45:57.137089   10746 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-g6zxf/test-mhc-9p8nn/test-mhc-machine-cpb29/"
I0619 14:45:57.164063   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9p8nn" "namespace"="test-mhc-g6zxf" 
I0619 14:45:57.164707   10746 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-g6zxf/test-mhc-9p8nn/test-mhc-machine-cpb29/"
I0619 14:45:57.173622   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9p8nn" "namespace"="test-mhc-g6zxf" 
I0619 14:45:57.174028   10746 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-g6zxf/test-mhc-9p8nn/test-mhc-machine-cpb29/"
node created: test-mhc-node-8b5dr
E0619 14:45:57.182232   10746 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-8b5dr"
E0619 14:45:57.182435   10746 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8b5dr, got []"  "node"="test-mhc-node-8b5dr"
I0619 14:45:57.187318   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9p8nn" "namespace"="test-mhc-g6zxf" 
I0619 14:45:57.187760   10746 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-g6zxf/test-mhc-9p8nn/test-mhc-machine-cpb29/"
I0619 14:45:57.194033   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9p8nn" "namespace"="test-mhc-g6zxf" 
I0619 14:45:57.210350   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9p8nn" "namespace"="test-mhc-g6zxf" 
I0619 14:45:57.212097   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9p8nn" "namespace"="test-mhc-g6zxf" 
Cleaning up nodes, machines and infra machines.
I0619 14:45:57.216583   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9p8nn" "namespace"="test-mhc-g6zxf" 
I0619 14:45:57.219576   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9p8nn" "namespace"="test-mhc-g6zxf" 
I0619 14:45:57.220053   10746 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-g6zxf/test-mhc-9p8nn/test-mhc-machine-q5k2l/"
E0619 14:45:57.237968   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"test-mhc-machine-q5k2l\" in namespace \"test-mhc-g6zxf\": cannot find node with matching ProviderID" "controller"="machine" "name"="test-mhc-machine-q5k2l" "namespace"="test-mhc-g6zxf"
E0619 14:45:57.255153   10746 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-g6zxf/test-cluster-cm6hc"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
inframachine created: test-mhc-machine-infra-fmbzv
machine created: test-mhc-machine-h6c5l
E0619 14:45:57.452449   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-9p8nn\" not found" "controller"="machinehealthcheck" "name"="test-mhc-9p8nn" "namespace"="test-mhc-g6zxf"
E0619 14:45:57.460150   10746 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-2mklb/machine-reconcile-w9q2m"
E0619 14:45:58.238363   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-cm6hc\" for machine \"test-mhc-machine-cpb29\" in namespace \"test-mhc-g6zxf\": Cluster.cluster.x-k8s.io \"test-cluster-cm6hc\" not found" "controller"="machine" "name"="test-mhc-machine-cpb29" "namespace"="test-mhc-g6zxf"
I0619 14:45:58.453803   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:45:58.494204   10746 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0619 14:45:58.528317   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9p8nn" "namespace"="test-mhc-g6zxf" 
I0619 14:45:58.528393   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:45:58.533850   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:45:58.534946   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
... skipping 326 lines ...
I0619 14:45:59.228462   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:45:59.230278   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:45:59.232034   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:45:59.233773   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:45:59.235788   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:45:59.237554   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
E0619 14:45:59.238664   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-cm6hc\" for machine \"test-mhc-machine-q5k2l\" in namespace \"test-mhc-g6zxf\": Cluster.cluster.x-k8s.io \"test-cluster-cm6hc\" not found" "controller"="machine" "name"="test-mhc-machine-q5k2l" "namespace"="test-mhc-g6zxf"
I0619 14:45:59.239261   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:45:59.240977   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:45:59.242682   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:45:59.244351   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:45:59.246435   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:45:59.248073   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
... skipping 460 lines ...
I0619 14:46:00.246245   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:00.247939   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:00.248781   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:00.250101   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:00.251983   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:00.253822   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
E0619 14:46:00.254011   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-cm6hc\" for machine \"test-mhc-machine-cpb29\" in namespace \"test-mhc-g6zxf\": Cluster.cluster.x-k8s.io \"test-cluster-cm6hc\" not found" "controller"="machine" "name"="test-mhc-machine-cpb29" "namespace"="test-mhc-g6zxf"
I0619 14:46:00.255026   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:00.255493   10746 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-xs2zs/test-mhc-pjr92/test-mhc-machine-h6c5l/"
I0619 14:46:00.265319   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:00.265614   10746 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-xs2zs/test-mhc-pjr92/test-mhc-machine-h6c5l/"
E0619 14:46:00.315421   10746 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-9q777, got []"  "node"="test-mhc-node-9q777"
node created: test-mhc-node-9q777
I0619 14:46:00.322830   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
inframachine created: test-mhc-machine-infra-vzblx
machine created: test-mhc-machine-x2d6x
I0619 14:46:00.385129   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:00.391175   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
... skipping 327 lines ...
I0619 14:46:01.240944   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:01.243218   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:01.245616   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:01.248249   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:01.250692   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:01.252709   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
E0619 14:46:01.254329   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-cm6hc\" for machine \"test-mhc-machine-q5k2l\" in namespace \"test-mhc-g6zxf\": Cluster.cluster.x-k8s.io \"test-cluster-cm6hc\" not found" "controller"="machine" "name"="test-mhc-machine-q5k2l" "namespace"="test-mhc-g6zxf"
I0619 14:46:01.254680   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:01.256625   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:01.258674   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:01.260719   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:01.262955   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:01.265059   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
... skipping 422 lines ...
I0619 14:46:02.312241   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:02.313530   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:02.314819   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:02.316076   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:02.318159   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:02.323887   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
E0619 14:46:02.324190   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-cm6hc\" for machine \"test-mhc-machine-cpb29\" in namespace \"test-mhc-g6zxf\": Cluster.cluster.x-k8s.io \"test-cluster-cm6hc\" not found" "controller"="machine" "name"="test-mhc-machine-cpb29" "namespace"="test-mhc-g6zxf"
I0619 14:46:02.325449   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:02.326785   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:02.329300   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:02.331640   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:02.332963   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:02.334251   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
... skipping 366 lines ...
I0619 14:46:03.332498   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:03.334813   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:03.337147   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:03.338162   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:03.339421   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:03.341499   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:03.341859   10746 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-xs2zs/test-mhc-pjr92/test-mhc-machine-x2d6x/"
E0619 14:46:03.341980   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-cm6hc\" for machine \"test-mhc-machine-q5k2l\" in namespace \"test-mhc-g6zxf\": Cluster.cluster.x-k8s.io \"test-cluster-cm6hc\" not found" "controller"="machine" "name"="test-mhc-machine-q5k2l" "namespace"="test-mhc-g6zxf"
I0619 14:46:03.352341   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:03.352729   10746 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-xs2zs/test-mhc-pjr92/test-mhc-machine-x2d6x/"
E0619 14:46:03.380542   10746 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-z89d9, got []"  "node"="test-mhc-node-z89d9"
node created: test-mhc-node-z89d9
I0619 14:46:03.388259   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
inframachine created: test-mhc-machine-infra-gplnf
I0619 14:46:03.403983   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
machine created: test-mhc-machine-g4v5j
I0619 14:46:03.412833   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
... skipping 278 lines ...
I0619 14:46:04.355329   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:04.356879   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:04.358408   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:04.359741   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:04.361409   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:04.362898   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
E0619 14:46:04.363258   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-cm6hc\" for machine \"test-mhc-machine-cpb29\" in namespace \"test-mhc-g6zxf\": Cluster.cluster.x-k8s.io \"test-cluster-cm6hc\" not found" "controller"="machine" "name"="test-mhc-machine-cpb29" "namespace"="test-mhc-g6zxf"
I0619 14:46:04.364239   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:04.365433   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:04.366690   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:04.367986   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:04.369289   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:04.372154   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
... skipping 343 lines ...
I0619 14:46:05.400182   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:05.401959   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:05.403355   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:05.404733   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:05.410830   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:05.412364   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
E0619 14:46:05.420924   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-cm6hc\" for machine \"test-mhc-machine-q5k2l\" in namespace \"test-mhc-g6zxf\": Cluster.cluster.x-k8s.io \"test-cluster-cm6hc\" not found" "controller"="machine" "name"="test-mhc-machine-q5k2l" "namespace"="test-mhc-g6zxf"
I0619 14:46:05.426716   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:05.428524   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:05.429817   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:05.431167   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:05.432563   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:05.433840   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
... skipping 294 lines ...
I0619 14:46:06.424281   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:06.427512   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:06.429907   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:06.431437   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:06.433010   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:06.434461   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:06.434938   10746 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-xs2zs/test-mhc-pjr92/test-mhc-machine-g4v5j/"
E0619 14:46:06.438905   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-cm6hc\" for machine \"test-mhc-machine-cpb29\" in namespace \"test-mhc-g6zxf\": Cluster.cluster.x-k8s.io \"test-cluster-cm6hc\" not found" "controller"="machine" "name"="test-mhc-machine-cpb29" "namespace"="test-mhc-g6zxf"
node created: test-mhc-node-wq62q
E0619 14:46:06.447047   10746 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-wq62q, got []"  "node"="test-mhc-node-wq62q"
I0619 14:46:06.448069   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:06.448580   10746 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-xs2zs/test-mhc-pjr92/test-mhc-machine-g4v5j/"
Cleaning up nodes, machines and infra machines.
I0619 14:46:06.454443   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:06.454947   10746 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-xs2zs/test-mhc-pjr92/test-mhc-machine-g4v5j/test-mhc-node-wq62q"
I0619 14:46:06.465388   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pjr92" "namespace"="test-mhc-xs2zs" 
I0619 14:46:06.465866   10746 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-xs2zs/test-mhc-pjr92/test-mhc-machine-g4v5j/"
Cleaning up nodes, machines and infra machines.
I0619 14:46:06.510871   10746 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-mbn4m" "namespace"="test-mhc-xs2zs" "count"=2
I0619 14:46:06.510974   10746 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-mbn4m" "namespace"="test-mhc-xs2zs" "descendants"="Worker machines: test-mhc-machine-h6c5l,test-mhc-machine-x2d6x,test-mhc-machine-g4v5j" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
I0619 14:46:06.516279   10746 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-mbn4m" "namespace"="test-mhc-xs2zs" "count"=2
I0619 14:46:06.516329   10746 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-mbn4m" "namespace"="test-mhc-xs2zs" "descendants"="Worker machines: test-mhc-machine-h6c5l,test-mhc-machine-x2d6x,test-mhc-machine-g4v5j" "indirect descendants count"=1
... skipping 7 lines ...
I0619 14:46:06.714268   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:06.755215   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:06.838925   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:07.000388   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:07.321354   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:07.439443   10746 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-mbn4m" "machine"="test-mhc-machine-x2d6x" "namespace"="test-mhc-xs2zs" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-z89d9"}
E0619 14:46:07.483998   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-x2d6x\" not found" "controller"="machine" "name"="test-mhc-machine-x2d6x" "namespace"="test-mhc-xs2zs"
I0619 14:46:07.964048   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
E0619 14:46:08.496215   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-cm6hc\" for machine \"test-mhc-machine-q5k2l\" in namespace \"test-mhc-g6zxf\": Cluster.cluster.x-k8s.io \"test-cluster-cm6hc\" not found" "controller"="machine" "name"="test-mhc-machine-q5k2l" "namespace"="test-mhc-g6zxf"
I0619 14:46:09.245190   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:09.496771   10746 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-mbn4m" "machine"="test-mhc-machine-g4v5j" "namespace"="test-mhc-xs2zs" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-wq62q"}
E0619 14:46:09.547794   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-g4v5j\" not found" "controller"="machine" "name"="test-mhc-machine-g4v5j" "namespace"="test-mhc-xs2zs"
I0619 14:46:10.548392   10746 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-mbn4m" "machine"="test-mhc-machine-h6c5l" "namespace"="test-mhc-xs2zs" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-9q777"}
E0619 14:46:10.593453   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-h6c5l\" not found" "controller"="machine" "name"="test-mhc-machine-h6c5l" "namespace"="test-mhc-xs2zs"
E0619 14:46:11.528370   10746 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-xs2zs/test-cluster-mbn4m"
I0619 14:46:11.607109   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:11.615664   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
E0619 14:46:11.617100   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-cm6hc\" for machine \"test-mhc-machine-cpb29\" in namespace \"test-mhc-g6zxf\": Cluster.cluster.x-k8s.io \"test-cluster-cm6hc\" not found" "controller"="machine" "name"="test-mhc-machine-cpb29" "namespace"="test-mhc-g6zxf"
I0619 14:46:11.637731   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
E0619 14:46:11.698574   10746 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-w7h44, got []"  "node"="test-mhc-node-w7h44"
node created: test-mhc-node-w7h44
I0619 14:46:11.706007   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
inframachine created: test-mhc-machine-infra-9vqlf
machine created: test-mhc-machine-bbjml
I0619 14:46:11.724890   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:11.735768   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:11.736878   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:11.741293   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:11.784051   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:11.865370   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:12.026677   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:12.347918   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
E0619 14:46:12.617493   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-cm6hc\" for machine \"test-mhc-machine-q5k2l\" in namespace \"test-mhc-g6zxf\": Cluster.cluster.x-k8s.io \"test-cluster-cm6hc\" not found" "controller"="machine" "name"="test-mhc-machine-q5k2l" "namespace"="test-mhc-g6zxf"
I0619 14:46:12.990243   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:13.638656   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:13.656206   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:13.664331   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:13.668923   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:13.688813   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:13.694527   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
E0619 14:46:13.695060   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-cm6hc\" for machine \"test-mhc-machine-cpb29\" in namespace \"test-mhc-g6zxf\": Cluster.cluster.x-k8s.io \"test-cluster-cm6hc\" not found" "controller"="machine" "name"="test-mhc-machine-cpb29" "namespace"="test-mhc-g6zxf"
I0619 14:46:13.714462   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
node created: test-mhc-node-h4njc
E0619 14:46:13.734779   10746 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-h4njc, got []"  "node"="test-mhc-node-h4njc"
I0619 14:46:13.740925   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
inframachine created: test-mhc-machine-infra-qdmkz
I0619 14:46:13.753920   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:13.759359   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
machine created: test-mhc-machine-kcjkc
I0619 14:46:13.773269   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:13.779708   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:14.271584   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
E0619 14:46:14.695422   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-cm6hc\" for machine \"test-mhc-machine-q5k2l\" in namespace \"test-mhc-g6zxf\": Cluster.cluster.x-k8s.io \"test-cluster-cm6hc\" not found" "controller"="machine" "name"="test-mhc-machine-q5k2l" "namespace"="test-mhc-g6zxf"
I0619 14:46:15.708086   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:15.727092   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:15.732781   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:15.744029   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:15.756469   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:15.782834   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
E0619 14:46:15.792337   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-cm6hc\" for machine \"test-mhc-machine-cpb29\" in namespace \"test-mhc-g6zxf\": Cluster.cluster.x-k8s.io \"test-cluster-cm6hc\" not found" "controller"="machine" "name"="test-mhc-machine-cpb29" "namespace"="test-mhc-g6zxf"
I0619 14:46:15.792760   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:15.834374   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
node created: test-mhc-node-mwh2m
E0619 14:46:15.875206   10746 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-mwh2m, got []"  "node"="test-mhc-node-mwh2m"
I0619 14:46:15.882013   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
Cleaning up nodes, machines and infra machines.
I0619 14:46:15.892721   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
Cleaning up nodes, machines and infra machines.
I0619 14:46:15.924163   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:15.929754   10746 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-n7w79" "namespace"="test-mhc-qmpcx" "count"=2
I0619 14:46:15.929830   10746 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-n7w79" "namespace"="test-mhc-qmpcx" "descendants"="Worker machines: test-mhc-machine-s5p97,test-mhc-machine-bbjml,test-mhc-machine-kcjkc" "indirect descendants count"=1
I0619 14:46:15.936003   10746 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-n7w79" "namespace"="test-mhc-qmpcx" "count"=2
I0619 14:46:15.936065   10746 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-n7w79" "namespace"="test-mhc-qmpcx" "descendants"="Worker machines: test-mhc-machine-s5p97,test-mhc-machine-bbjml,test-mhc-machine-kcjkc" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_less_than_the_NodeStartupTimeout
E0619 14:46:15.941188   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-m2wjv\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-m2wjv\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx"
inframachine created: test-mhc-machine-infra-htlx6
machine created: test-mhc-machine-rdnmt
E0619 14:46:16.792730   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-cm6hc\" for machine \"test-mhc-machine-q5k2l\" in namespace \"test-mhc-g6zxf\": Cluster.cluster.x-k8s.io \"test-cluster-cm6hc\" not found" "controller"="machine" "name"="test-mhc-machine-q5k2l" "namespace"="test-mhc-g6zxf"
I0619 14:46:16.941445   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m2wjv" "namespace"="test-mhc-qmpcx" 
I0619 14:46:16.941560   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbgr" "namespace"="test-mhc-fskvw" 
I0619 14:46:16.957038   10746 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0619 14:46:17.094351   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbgr" "namespace"="test-mhc-fskvw" 
I0619 14:46:17.095121   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbgr" "namespace"="test-mhc-fskvw" 
I0619 14:46:17.796309   10746 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-n7w79" "machine"="test-mhc-machine-s5p97" "namespace"="test-mhc-qmpcx" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-w7h44"}
E0619 14:46:17.839708   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-s5p97\" not found" "controller"="machine" "name"="test-mhc-machine-s5p97" "namespace"="test-mhc-qmpcx"
I0619 14:46:18.840243   10746 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-n7w79" "machine"="test-mhc-machine-bbjml" "namespace"="test-mhc-qmpcx" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-h4njc"}
E0619 14:46:18.884454   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-bbjml\" not found" "controller"="machine" "name"="test-mhc-machine-bbjml" "namespace"="test-mhc-qmpcx"
I0619 14:46:19.884952   10746 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-n7w79" "machine"="test-mhc-machine-kcjkc" "namespace"="test-mhc-qmpcx" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-mwh2m"}
E0619 14:46:19.928303   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-kcjkc\" not found" "controller"="machine" "name"="test-mhc-machine-kcjkc" "namespace"="test-mhc-qmpcx"
I0619 14:46:20.940411   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbgr" "namespace"="test-mhc-fskvw" 
E0619 14:46:20.949866   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-cm6hc\" for machine \"test-mhc-machine-cpb29\" in namespace \"test-mhc-g6zxf\": Cluster.cluster.x-k8s.io \"test-cluster-cm6hc\" not found" "controller"="machine" "name"="test-mhc-machine-cpb29" "namespace"="test-mhc-g6zxf"
I0619 14:46:20.950451   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbgr" "namespace"="test-mhc-fskvw" 
E0619 14:46:20.951511   10746 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-qmpcx/test-cluster-n7w79"
node created: test-mhc-node-nszgt
E0619 14:46:21.020049   10746 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-nszgt, got []"  "node"="test-mhc-node-nszgt"
I0619 14:46:21.027407   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbgr" "namespace"="test-mhc-fskvw" 
inframachine created: test-mhc-machine-infra-dknsc
machine created: test-mhc-machine-g9kg8
I0619 14:46:21.041405   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbgr" "namespace"="test-mhc-fskvw" 
I0619 14:46:21.045819   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbgr" "namespace"="test-mhc-fskvw" 
E0619 14:46:21.950287   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-cm6hc\" for machine \"test-mhc-machine-q5k2l\" in namespace \"test-mhc-g6zxf\": Cluster.cluster.x-k8s.io \"test-cluster-cm6hc\" not found" "controller"="machine" "name"="test-mhc-machine-q5k2l" "namespace"="test-mhc-g6zxf"
I0619 14:46:22.966968   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbgr" "namespace"="test-mhc-fskvw" 
I0619 14:46:22.972287   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbgr" "namespace"="test-mhc-fskvw" 
I0619 14:46:22.982882   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbgr" "namespace"="test-mhc-fskvw" 
I0619 14:46:22.989599   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbgr" "namespace"="test-mhc-fskvw" 
I0619 14:46:22.998287   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbgr" "namespace"="test-mhc-fskvw" 
I0619 14:46:23.004955   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbgr" "namespace"="test-mhc-fskvw" 
I0619 14:46:23.015922   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbgr" "namespace"="test-mhc-fskvw" 
I0619 14:46:23.031142   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbgr" "namespace"="test-mhc-fskvw" 
I0619 14:46:23.048288   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbgr" "namespace"="test-mhc-fskvw" 
I0619 14:46:23.054443   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbgr" "namespace"="test-mhc-fskvw" 
node created: test-mhc-node-766pw
E0619 14:46:23.067215   10746 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-766pw, got []"  "node"="test-mhc-node-766pw"
I0619 14:46:23.079803   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbgr" "namespace"="test-mhc-fskvw" 
I0619 14:46:23.090895   10746 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-g9kg8" "namespace"="test-mhc-fskvw" "noderef"="test-mhc-node-766pw"
inframachine created: test-mhc-machine-infra-pl8fw
machine created: test-mhc-machine-kwxtz
I0619 14:46:23.124889   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbgr" "namespace"="test-mhc-fskvw" 
I0619 14:46:23.133184   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbgr" "namespace"="test-mhc-fskvw" 
... skipping 4 lines ...
I0619 14:46:23.190284   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbgr" "namespace"="test-mhc-fskvw" 
Cleaning up nodes, machines and infra machines.
I0619 14:46:23.230116   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbgr" "namespace"="test-mhc-fskvw" 
I0619 14:46:23.236367   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbgr" "namespace"="test-mhc-fskvw" 
Cleaning up nodes, machines and infra machines.
I0619 14:46:23.247761   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbgr" "namespace"="test-mhc-fskvw" 
I0619 14:46:23.248360   10746 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-fskvw/test-mhc-4zbgr/test-mhc-machine-rdnmt/"
I0619 14:46:23.248973   10746 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-95jxv" "machine"="test-mhc-machine-kwxtz" "namespace"="test-mhc-fskvw" "cause"="noderef is nil" "node"=null
I0619 14:46:23.272288   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbgr" "namespace"="test-mhc-fskvw" 
I0619 14:46:23.272972   10746 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-fskvw/test-mhc-4zbgr/test-mhc-machine-rdnmt/"
I0619 14:46:23.273495   10746 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-fskvw/test-mhc-4zbgr/test-mhc-machine-g9kg8/"
I0619 14:46:23.300336   10746 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-95jxv" "namespace"="test-mhc-fskvw" "count"=2
I0619 14:46:23.300406   10746 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-95jxv" "namespace"="test-mhc-fskvw" "descendants"="Worker machines: test-mhc-machine-rdnmt,test-mhc-machine-g9kg8" "indirect descendants count"=0
E0619 14:46:23.301063   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-kwxtz\" not found" "controller"="machine" "name"="test-mhc-machine-kwxtz" "namespace"="test-mhc-fskvw"
I0619 14:46:23.304237   10746 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-95jxv" "namespace"="test-mhc-fskvw" "count"=2
I0619 14:46:23.304303   10746 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-95jxv" "namespace"="test-mhc-fskvw" "descendants"="Worker machines: test-mhc-machine-rdnmt,test-mhc-machine-g9kg8" "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-kfd89
machine created: test-mhc-machine-c8r6q
E0619 14:46:23.455397   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-4zbgr\" not found" "controller"="machinehealthcheck" "name"="test-mhc-4zbgr" "namespace"="test-mhc-fskvw"
I0619 14:46:24.301769   10746 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-95jxv" "machine"="test-mhc-machine-rdnmt" "namespace"="test-mhc-fskvw" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-nszgt"}
E0619 14:46:24.349608   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-rdnmt\" not found" "controller"="machine" "name"="test-mhc-machine-rdnmt" "namespace"="test-mhc-fskvw"
I0619 14:46:24.455649   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
I0619 14:46:24.487864   10746 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0619 14:46:24.516646   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zbgr" "namespace"="test-mhc-fskvw" 
I0619 14:46:24.516715   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
I0619 14:46:24.517753   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
I0619 14:46:24.519773   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
... skipping 424 lines ...
I0619 14:46:25.395509   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
I0619 14:46:25.401717   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
I0619 14:46:25.404193   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
I0619 14:46:25.405874   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
I0619 14:46:25.407533   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
I0619 14:46:25.409222   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
E0619 14:46:25.410122   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-g9kg8\" not found" "controller"="machine" "name"="test-mhc-machine-g9kg8" "namespace"="test-mhc-fskvw"
I0619 14:46:25.410951   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
I0619 14:46:25.412685   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
I0619 14:46:25.414381   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
I0619 14:46:25.416079   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
I0619 14:46:25.417768   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
I0619 14:46:25.419472   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
... skipping 497 lines ...
I0619 14:46:26.415776   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
I0619 14:46:26.417476   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
I0619 14:46:26.418341   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
I0619 14:46:26.419098   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
I0619 14:46:26.420800   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
I0619 14:46:26.422454   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
E0619 14:46:26.423537   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-cm6hc\" for machine \"test-mhc-machine-cpb29\" in namespace \"test-mhc-g6zxf\": Cluster.cluster.x-k8s.io \"test-cluster-cm6hc\" not found" "controller"="machine" "name"="test-mhc-machine-cpb29" "namespace"="test-mhc-g6zxf"
I0619 14:46:26.423574   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
I0619 14:46:26.423791   10746 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-tg2tl/test-mhc-svkmj/test-mhc-machine-c8r6q/"
I0619 14:46:26.432875   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
I0619 14:46:26.433204   10746 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-tg2tl/test-mhc-svkmj/test-mhc-machine-c8r6q/"
E0619 14:46:26.456779   10746 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6s65c, got []"  "node"="test-mhc-node-6s65c"
E0619 14:46:26.456779   10746 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6s65c, got []"  "node"="test-mhc-node-6s65c"
node created: test-mhc-node-6s65c
I0619 14:46:26.464847   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
I0619 14:46:26.486439   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
I0619 14:46:26.496252   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
I0619 14:46:26.497484   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
I0619 14:46:26.499145   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
I0619 14:46:26.499614   10746 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-tg2tl/test-mhc-svkmj/test-mhc-machine-c8r6q/test-mhc-node-6s65c"
I0619 14:46:26.523073   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
I0619 14:46:26.523661   10746 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-tg2tl/test-mhc-svkmj/test-mhc-machine-c8r6q/test-mhc-node-6s65c"
Cleaning up nodes, machines and infra machines.
I0619 14:46:26.534074   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
I0619 14:46:26.534431   10746 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-tg2tl/test-mhc-svkmj/test-mhc-machine-c8r6q/"
I0619 14:46:26.568544   10746 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-mb9l7" "namespace"="test-mhc-tg2tl" "descendants"="Worker machines: test-mhc-machine-c8r6q" "indirect descendants count"=1
I0619 14:46:26.575200   10746 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-mb9l7" "namespace"="test-mhc-tg2tl" "descendants"="Worker machines: test-mhc-machine-c8r6q" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0619 14:46:26.683954   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-svkmj" "namespace"="test-mhc-tg2tl" 
I0619 14:46:26.713122   10746 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-qvjwd" "namespace"="test-mhc-46jsj" "creating"=1 "need"=1
I0619 14:46:26.713174   10746 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-qvjwd" "namespace"="test-mhc-46jsj" 
I0619 14:46:26.723363   10746 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-qvjwd-lsz47\"" "machineset"="mhc-ms-qvjwd" "namespace"="test-mhc-46jsj" 
I0619 14:46:26.798790   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gh2sm" "namespace"="test-mhc-46jsj" 
I0619 14:46:26.818759   10746 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0619 14:46:26.859806   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gh2sm" "namespace"="test-mhc-46jsj" 
I0619 14:46:26.860682   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gh2sm" "namespace"="test-mhc-46jsj" 
I0619 14:46:26.885979   10746 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-qvjwd" "namespace"="test-mhc-46jsj" 
E0619 14:46:27.423967   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-cm6hc\" for machine \"test-mhc-machine-q5k2l\" in namespace \"test-mhc-g6zxf\": Cluster.cluster.x-k8s.io \"test-cluster-cm6hc\" not found" "controller"="machine" "name"="test-mhc-machine-q5k2l" "namespace"="test-mhc-g6zxf"
I0619 14:46:27.860020   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gh2sm" "namespace"="test-mhc-46jsj" 
E0619 14:46:28.316988   10746 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-fskvw/test-cluster-95jxv"
I0619 14:46:28.424603   10746 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-mb9l7" "machine"="test-mhc-machine-c8r6q" "namespace"="test-mhc-tg2tl" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-6s65c"}
E0619 14:46:28.479728   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-c8r6q\" not found" "controller"="machine" "name"="test-mhc-machine-c8r6q" "namespace"="test-mhc-tg2tl"
I0619 14:46:28.861053   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gh2sm" "namespace"="test-mhc-46jsj" 
I0619 14:46:29.489886   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gh2sm" "namespace"="test-mhc-46jsj" 
I0619 14:46:29.490436   10746 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-qvjwd" "namespace"="test-mhc-46jsj" 
I0619 14:46:29.497981   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gh2sm" "namespace"="test-mhc-46jsj" 
I0619 14:46:29.498827   10746 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-qvjwd" "namespace"="test-mhc-46jsj" 
I0619 14:46:29.511872   10746 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-qvjwd-lsz47" "namespace"="test-mhc-46jsj" 
... skipping 5 lines ...
I0619 14:46:29.531655   10746 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-qvjwd-lsz47" "namespace"="test-mhc-46jsj" 
I0619 14:46:29.531694   10746 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-qvjwd-lsz47" "namespace"="test-mhc-46jsj" 
I0619 14:46:29.862206   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gh2sm" "namespace"="test-mhc-46jsj" 
I0619 14:46:30.530509   10746 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-qvjwd-lsz47" "namespace"="test-mhc-46jsj" 
I0619 14:46:30.530557   10746 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-qvjwd-lsz47" "namespace"="test-mhc-46jsj" 
I0619 14:46:31.000586   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gh2sm" "namespace"="test-mhc-46jsj" 
I0619 14:46:31.000923   10746 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-46jsj/test-mhc-gh2sm/mhc-ms-qvjwd-lsz47/"
I0619 14:46:31.008015   10746 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-qvjwd" "namespace"="test-mhc-46jsj" 
I0619 14:46:31.024289   10746 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-qvjwd-lsz47" "namespace"="test-mhc-46jsj" 
I0619 14:46:31.024329   10746 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-qvjwd-lsz47" "namespace"="test-mhc-46jsj" 
I0619 14:46:31.026554   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gh2sm" "namespace"="test-mhc-46jsj" 
I0619 14:46:31.026863   10746 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-46jsj/test-mhc-gh2sm/mhc-ms-qvjwd-lsz47/"
I0619 14:46:31.030985   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gh2sm" "namespace"="test-mhc-46jsj" 
I0619 14:46:31.031297   10746 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-46jsj/test-mhc-gh2sm/mhc-ms-qvjwd-lsz47/"
I0619 14:46:31.032164   10746 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-qvjwd" "namespace"="test-mhc-46jsj" 
I0619 14:46:31.056443   10746 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-9hsh6" "namespace"="test-mhc-46jsj" "count"=1
I0619 14:46:31.056515   10746 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-9hsh6" "namespace"="test-mhc-46jsj" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-qvjwd"
I0619 14:46:31.056570   10746 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-qvjwd-lsz47" "namespace"="test-mhc-46jsj" 
I0619 14:46:31.056604   10746 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-qvjwd-lsz47" "namespace"="test-mhc-46jsj" 
I0619 14:46:31.058668   10746 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-qvjwd" "namespace"="test-mhc-46jsj" "machine"="mhc-ms-qvjwd-lsz47"
I0619 14:46:31.061668   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gh2sm" "namespace"="test-mhc-46jsj" 
I0619 14:46:31.069771   10746 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-9hsh6" "namespace"="test-mhc-46jsj" "descendants"="Machine sets: mhc-ms-qvjwd;Worker machines: mhc-ms-qvjwd-lsz47" "indirect descendants count"=1
I0619 14:46:31.070680   10746 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-9hsh6" "machine"="mhc-ms-qvjwd-lsz47" "namespace"="test-mhc-46jsj" "cause"="cluster is being deleted" "node"=null
I0619 14:46:31.077502   10746 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-9hsh6" "namespace"="test-mhc-46jsj" "descendants"="Worker machines: mhc-ms-qvjwd-lsz47" "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
E0619 14:46:31.080872   10746 machineset_controller.go:151] controllers/MachineSet "msg"="Failed to reconcile MachineSet" "error"="failed to patch MachineSet's Status: machinesets.cluster.x-k8s.io \"mhc-ms-qvjwd\" not found" "machineset"="mhc-ms-qvjwd" "namespace"="test-mhc-46jsj" 
E0619 14:46:31.080938   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to patch MachineSet's Status: machinesets.cluster.x-k8s.io \"mhc-ms-qvjwd\" not found" "controller"="machineset" "name"="mhc-ms-qvjwd" "namespace"="test-mhc-46jsj"
I0619 14:46:31.185432   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m952x" "namespace"="test-mhc-jfvzj" 
inframachine created: test-mhc-machine-infra-7s5rj
I0619 14:46:31.218775   10746 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-v5vzx
I0619 14:46:31.239562   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m952x" "namespace"="test-mhc-jfvzj" 
I0619 14:46:31.245327   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m952x" "namespace"="test-mhc-jfvzj" 
... skipping 11 lines ...
I0619 14:46:31.266121   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m952x" "namespace"="test-mhc-jfvzj" 
I0619 14:46:31.266671   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m952x" "namespace"="test-mhc-jfvzj" 
I0619 14:46:31.268328   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m952x" "namespace"="test-mhc-jfvzj" 
I0619 14:46:31.270311   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m952x" "namespace"="test-mhc-jfvzj" 
I0619 14:46:31.271889   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m952x" "namespace"="test-mhc-jfvzj" 
I0619 14:46:31.272384   10746 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-9hsh6" "machine"="mhc-ms-qvjwd-lsz47" "namespace"="test-mhc-46jsj" "cause"="cluster is being deleted" "node"=null
E0619 14:46:31.312403   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-qvjwd-lsz47\" not found" "controller"="machine" "name"="mhc-ms-qvjwd-lsz47" "namespace"="test-mhc-46jsj"
E0619 14:46:31.332393   10746 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-q2lwc, got []"  "node"="test-mhc-node-q2lwc"
E0619 14:46:31.332393   10746 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-q2lwc, got []"  "node"="test-mhc-node-q2lwc"
E0619 14:46:31.332451   10746 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-q2lwc, got []"  "node"="test-mhc-node-q2lwc"
node created: test-mhc-node-q2lwc
I0619 14:46:31.345615   10746 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-v5vzx" "target"="test-mhc-jfvzj/test-mhc-m952x/test-mhc-machine-v5vzx/"
I0619 14:46:31.357428   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m952x" "namespace"="test-mhc-jfvzj" 
I0619 14:46:31.382007   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m952x" "namespace"="test-mhc-jfvzj" 
I0619 14:46:31.421632   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m952x" "namespace"="test-mhc-jfvzj" 
I0619 14:46:31.426009   10746 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-v5vzx" "target"="test-mhc-jfvzj/test-mhc-m952x/test-mhc-machine-v5vzx/test-mhc-node-q2lwc"
I0619 14:46:31.445689   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m952x" "namespace"="test-mhc-jfvzj" 
I0619 14:46:31.452245   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m952x" "namespace"="test-mhc-jfvzj" 
Cleaning up nodes, machines and infra machines.
I0619 14:46:31.458480   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m952x" "namespace"="test-mhc-jfvzj" 
I0619 14:46:31.461575   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m952x" "namespace"="test-mhc-jfvzj" 
I0619 14:46:31.466361   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-m952x" "namespace"="test-mhc-jfvzj" 
... skipping 8 lines ...
I0619 14:46:31.575365   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:31.576535   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:31.584002   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:31.585782   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:31.591955   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:31.594249   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
E0619 14:46:31.594294   10746 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-tg2tl/test-cluster-mb9l7"
I0619 14:46:31.596115   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:31.598249   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:31.600067   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:31.601865   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:31.603564   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:31.605310   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
... skipping 393 lines ...
I0619 14:46:32.362550   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:32.365614   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:32.367797   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:32.369682   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:32.371573   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:32.373340   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
E0619 14:46:32.375254   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-v5vzx\" not found" "controller"="machine" "name"="test-mhc-machine-v5vzx" "namespace"="test-mhc-jfvzj"
I0619 14:46:32.375384   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:32.377270   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:32.379326   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:32.381192   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:32.383338   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:32.386345   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
... skipping 545 lines ...
I0619 14:46:33.366806   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:33.368340   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:33.370140   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:33.371887   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:33.373516   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:33.375145   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
E0619 14:46:33.375599   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-cm6hc\" for machine \"test-mhc-machine-cpb29\" in namespace \"test-mhc-g6zxf\": Cluster.cluster.x-k8s.io \"test-cluster-cm6hc\" not found" "controller"="machine" "name"="test-mhc-machine-cpb29" "namespace"="test-mhc-g6zxf"
I0619 14:46:33.376756   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:33.378398   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:33.380179   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:33.381707   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:33.383265   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:33.384831   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
... skipping 571 lines ...
I0619 14:46:34.381277   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:34.384156   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:34.384810   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:34.387385   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:34.389575   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:34.391415   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
E0619 14:46:34.391686   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-cm6hc\" for machine \"test-mhc-machine-q5k2l\" in namespace \"test-mhc-g6zxf\": Cluster.cluster.x-k8s.io \"test-cluster-cm6hc\" not found" "controller"="machine" "name"="test-mhc-machine-q5k2l" "namespace"="test-mhc-g6zxf"
I0619 14:46:34.394155   10746 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-5tgvb" "target"="test-mhc-4qc7r/test-mhc-g5hdb/test-mhc-machine-5tgvb/"
I0619 14:46:34.404556   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
E0619 14:46:34.455287   10746 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-t6ct2, got []"  "node"="test-mhc-node-t6ct2"
E0619 14:46:34.455499   10746 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-t6ct2, got []"  "node"="test-mhc-node-t6ct2"
E0619 14:46:34.455665   10746 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-t6ct2, got []"  "node"="test-mhc-node-t6ct2"
node created: test-mhc-node-t6ct2
I0619 14:46:34.461523   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:34.476621   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:34.484289   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:34.486757   10746 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-5tgvb" "target"="test-mhc-4qc7r/test-mhc-g5hdb/test-mhc-machine-5tgvb/test-mhc-node-t6ct2"
I0619 14:46:34.497788   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:34.502172   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:34.507450   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:34.509358   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:34.523629   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:34.527754   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
Cleaning up nodes, machines and infra machines.
I0619 14:46:34.531883   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:34.534599   10746 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-5tgvb" "target"="test-mhc-4qc7r/test-mhc-g5hdb/test-mhc-machine-5tgvb/"
I0619 14:46:34.542669   10746 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-pnfbg" "namespace"="test-mhc-4qc7r" "descendants"="Worker machines: test-mhc-machine-5tgvb" "indirect descendants count"=1
I0619 14:46:34.545901   10746 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-pnfbg" "namespace"="test-mhc-4qc7r" "descendants"="Worker machines: test-mhc-machine-5tgvb" "indirect descendants count"=1
E0619 14:46:34.548870   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-g5hdb\" not found" "controller"="machinehealthcheck" "name"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r"
--- PASS: TestMachineHealthCheck_Reconcile (39.41s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist (0.06s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value (0.03s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present (0.14s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist (1.04s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones (0.24s)
... 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.40s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (3.07s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0619 14:46:34.552688   10746 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
E0619 14:46:34.553976   10746 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
E0619 14:46:34.555088   10746 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E0619 14:46:34.555244   10746 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
E0619 14:46:34.555505   10746 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
I0619 14:46:34.557456   10746 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0619 14:46:34.557823   10746 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0619 14:46:34.558912   10746 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
E0619 14:46:34.564885   10746 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
E0619 14:46:34.566127   10746 machineset_controller.go:569]  "msg"="Unable to convert selector" "error"="\"bad-operator\" is not a valid pod selector operator" "machine"="match" "machineset"="" "namespace"="" 
--- PASS: TestHasMatchingLabels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_and_machine_have_matching_labels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_and_machine_do_not_have_matching_labels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_has_empty_selector (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_has_bad_selector (0.00s)
=== RUN   TestMachineToDelete
... skipping 57 lines ...
=== RUN   TestGinkgoSuite
Running Suite: Controllers Suite
================================
Random Seed: 1655649939
Will run 16 of 16 specs

•E0619 14:46:34.685475   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-tx6gh\" not found" "controller"="cluster" "name"="test1-tx6gh" "namespace"="default"
I0619 14:46:35.392120   10746 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-pnfbg" "machine"="test-mhc-machine-5tgvb" "namespace"="test-mhc-4qc7r" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-t6ct2"}
E0619 14:46:35.425274   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-5tgvb\" not found" "controller"="machine" "name"="test-mhc-machine-5tgvb" "namespace"="test-mhc-4qc7r"
I0619 14:46:35.549156   10746 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-g5hdb" "namespace"="test-mhc-4qc7r" 
I0619 14:46:35.801768   10746 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-5gmxf" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
•I0619 14:46:35.916538   10746 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-5gmxf" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0619 14:46:35.920443   10746 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-5gmxf" "namespace"="default"
E0619 14:46:36.931658   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5gmxf: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5gmxf" "namespace"="default"
•E0619 14:46:37.941209   10746 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-46jsj/test-cluster-9hsh6"
E0619 14:46:37.951111   10746 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-jfvzj/test-cluster-27tm6"
E0619 14:46:37.961677   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-zjxjl\" not found" "controller"="cluster" "name"="test3-zjxjl" "namespace"="default"
E0619 14:46:38.962434   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5gmxf: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5gmxf" "namespace"="default"
E0619 14:46:39.971510   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5gmxf: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5gmxf" "namespace"="default"
•E0619 14:46:40.982437   10746 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-4qc7r/test-cluster-pnfbg"
E0619 14:46:40.985483   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-6qfcg: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6qfcg" "namespace"="default"
E0619 14:46:41.986177   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5gmxf: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5gmxf" "namespace"="default"
E0619 14:46:42.995217   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-6qfcg: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6qfcg" "namespace"="default"
•E0619 14:46:43.615987   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-cm6hc\" for machine \"test-mhc-machine-cpb29\" in namespace \"test-mhc-g6zxf\": Cluster.cluster.x-k8s.io \"test-cluster-cm6hc\" not found" "controller"="machine" "name"="test-mhc-machine-cpb29" "namespace"="test-mhc-g6zxf"
E0619 14:46:43.996041   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5gmxf: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5gmxf" "namespace"="default"
E0619 14:46:44.632123   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-cm6hc\" for machine \"test-mhc-machine-q5k2l\" in namespace \"test-mhc-g6zxf\": Cluster.cluster.x-k8s.io \"test-cluster-cm6hc\" not found" "controller"="machine" "name"="test-mhc-machine-q5k2l" "namespace"="test-mhc-g6zxf"
E0619 14:46:44.996763   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-6qfcg: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6qfcg" "namespace"="default"
E0619 14:46:46.006943   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5gmxf: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5gmxf" "namespace"="default"
I0619 14:46:46.093860   10746 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-7wng9" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0619 14:46:46.102862   10746 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-7wng9" "namespace"="default" 
E0619 14:46:46.117593   10746 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-7wng9" "namespace"="default"
E0619 14:46:47.007649   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-6qfcg: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6qfcg" "namespace"="default"
I0619 14:46:47.133576   10746 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-7wng9" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0619 14:46:47.133797   10746 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-7wng9" "namespace"="default" "noderef"="id-node-1"
E0619 14:46:47.148814   10746 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-7wng9" "namespace"="default"
E0619 14:46:48.011690   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5gmxf: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5gmxf" "namespace"="default"
•I0619 14:46:48.083456   10746 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"
I0619 14:46:48.084309   10746 machine_controller_phases.go:219]  "msg"="Bootstrap provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0619 14:46:48.084362   10746 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"
I0619 14:46:48.084919   10746 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0619 14:46:48.084946   10746 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0619 14:46:48.085361   10746 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
... skipping 13 lines ...
I0619 14:46:48.097425   10746 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"
•I0619 14:46:48.098843   10746 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"
I0619 14:46:48.099439   10746 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"
I0619 14:46:48.100050   10746 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0619 14:46:48.100080   10746 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0619 14:46:48.100517   10746 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0619 14:46:48.101677   10746 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" 
•I0619 14:46:48.149229   10746 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-jxfwq" "machine"="test6-7wng9" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"5f63e0d9-f2c0-4673-a770-50ed52bb1303","apiVersion":"v1"}
E0619 14:46:48.166394   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-7wng9\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-7wng9" "namespace"="default"
I0619 14:46:48.168011   10746 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-lgswk" "namespace"="ms-test" "creating"=2 "need"=2
I0619 14:46:48.168050   10746 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-lgswk" "namespace"="ms-test" 
I0619 14:46:48.180188   10746 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-lgswk-rgdnc\"" "machineset"="ms-lgswk" "namespace"="ms-test" 
I0619 14:46:48.180260   10746 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-lgswk" "namespace"="ms-test" 
I0619 14:46:48.191302   10746 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-lgswk-p4fbc\"" "machineset"="ms-lgswk" "namespace"="ms-test" 
E0619 14:46:49.012530   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-6qfcg: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6qfcg" "namespace"="default"
I0619 14:46:49.166907   10746 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-jxfwq" "machine"="test6-7wng9" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"5f63e0d9-f2c0-4673-a770-50ed52bb1303","apiVersion":"v1"}
E0619 14:46:49.167577   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-7wng9\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-7wng9" "namespace"="default"
I0619 14:46:50.013225   10746 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-jxfwq" "namespace"="default" "count"=1
I0619 14:46:50.013326   10746 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-jxfwq" "namespace"="default" "descendants"="Control plane machines: test6-7wng9" "indirect descendants count"=0
E0619 14:46:50.024827   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5gmxf: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5gmxf" "namespace"="default"
I0619 14:46:50.179742   10746 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-jxfwq" "machine"="test6-7wng9" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"5f63e0d9-f2c0-4673-a770-50ed52bb1303","apiVersion":"v1"}
E0619 14:46:50.180380   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-7wng9\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-7wng9" "namespace"="default"
E0619 14:46:51.025522   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-6qfcg: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6qfcg" "namespace"="default"
I0619 14:46:51.324135   10746 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-jxfwq" "machine"="test6-7wng9" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"5f63e0d9-f2c0-4673-a770-50ed52bb1303","apiVersion":"v1"}
E0619 14:46:51.324676   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-7wng9\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-7wng9" "namespace"="default"
I0619 14:46:52.026031   10746 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-jxfwq" "namespace"="default" "count"=1
I0619 14:46:52.026115   10746 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-jxfwq" "namespace"="default" "descendants"="Control plane machines: test6-7wng9" "indirect descendants count"=0
E0619 14:46:52.026691   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-6qfcg: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6qfcg" "namespace"="default"
I0619 14:46:52.333415   10746 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-jxfwq" "machine"="test6-7wng9" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"5f63e0d9-f2c0-4673-a770-50ed52bb1303","apiVersion":"v1"}
E0619 14:46:52.333975   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-7wng9\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-7wng9" "namespace"="default"
E0619 14:46:53.027365   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5gmxf: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5gmxf" "namespace"="default"
I0619 14:46:53.339006   10746 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-jxfwq" "machine"="test6-7wng9" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"5f63e0d9-f2c0-4673-a770-50ed52bb1303","apiVersion":"v1"}
E0619 14:46:53.339679   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-7wng9\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-7wng9" "namespace"="default"
E0619 14:46:54.028152   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-6qfcg: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6qfcg" "namespace"="default"
I0619 14:46:54.344557   10746 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-jxfwq" "machine"="test6-7wng9" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"5f63e0d9-f2c0-4673-a770-50ed52bb1303","apiVersion":"v1"}
E0619 14:46:54.345167   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-7wng9\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-7wng9" "namespace"="default"
E0619 14:46:55.028834   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-6qfcg: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6qfcg" "namespace"="default"
I0619 14:46:55.625625   10746 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-jxfwq" "machine"="test6-7wng9" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"5f63e0d9-f2c0-4673-a770-50ed52bb1303","apiVersion":"v1"}
E0619 14:46:55.626222   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-7wng9\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-7wng9" "namespace"="default"
I0619 14:46:56.029347   10746 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-jxfwq" "namespace"="default" "count"=1
I0619 14:46:56.029406   10746 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-jxfwq" "namespace"="default" "descendants"="Control plane machines: test6-7wng9" "indirect descendants count"=0
E0619 14:46:56.030041   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5gmxf: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5gmxf" "namespace"="default"
E0619 14:46:57.030869   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-6qfcg: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6qfcg" "namespace"="default"
I0619 14:46:58.186704   10746 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-jxfwq" "machine"="test6-7wng9" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"5f63e0d9-f2c0-4673-a770-50ed52bb1303","apiVersion":"v1"}
E0619 14:46:58.187429   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-7wng9\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-7wng9" "namespace"="default"
E0619 14:46:58.191655   10746 machineset_controller.go:476] controllers/MachineSet "msg"="Failed waiting for machine object to be created" "error"="timed out waiting for the condition"  
E0619 14:46:58.196013   10746 machineset_controller.go:151] controllers/MachineSet "msg"="Failed to reconcile MachineSet" "error"="failed to sync MachineSet replicas: failed waiting for machine object to be created: timed out waiting for the condition" "machineset"="ms-lgswk" "namespace"="ms-test" 
E0619 14:46:58.196087   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to sync MachineSet replicas: failed waiting for machine object to be created: timed out waiting for the condition" "controller"="machineset" "name"="ms-lgswk" "namespace"="ms-test"
I0619 14:46:59.202416   10746 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-lgswk" "namespace"="ms-test" "creating"=1 "need"=2
I0619 14:46:59.202457   10746 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-lgswk" "namespace"="ms-test" 
I0619 14:46:59.213009   10746 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-lgswk-wzp6f\"" "machineset"="ms-lgswk" "namespace"="ms-test" 
I0619 14:46:59.233111   10746 machine_controller_phases.go:219] controllers/Machine "msg"="Bootstrap provider is not ready, requeuing" "machine"="ms-lgswk-wzp6f" "namespace"="ms-test" 
I0619 14:46:59.239696   10746 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="ms-lgswk-wzp6f" "namespace"="ms-test" 
I0619 14:46:59.239734   10746 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="ms-lgswk-wzp6f" "namespace"="ms-test" 
... skipping 17 lines ...
------------------------------
I0619 14:46:59.570774   10746 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-w75jx-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0619 14:46:59.570816   10746 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-w75jx-6657c7fddb" "namespace"="md-test" 
I0619 14:46:59.578365   10746 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-w75jx-6657c7fddb-9tdn2\"" "machineset"="md-w75jx-6657c7fddb" "namespace"="md-test" 
I0619 14:46:59.578411   10746 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-w75jx-6657c7fddb" "namespace"="md-test" 
I0619 14:46:59.590394   10746 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-w75jx-6657c7fddb-wdw6k\"" "machineset"="md-w75jx-6657c7fddb" "namespace"="md-test" 
E0619 14:46:59.591177   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-6qfcg: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-6qfcg" "namespace"="default"
I0619 14:46:59.596198   10746 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-w75jx-6657c7fddb-9tdn2" "namespace"="md-test" 
I0619 14:46:59.596231   10746 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-w75jx-6657c7fddb-9tdn2" "namespace"="md-test" 
I0619 14:46:59.617501   10746 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-w75jx-6657c7fddb-9tdn2" "namespace"="md-test" 
I0619 14:46:59.617531   10746 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-w75jx-6657c7fddb-9tdn2" "namespace"="md-test" 
I0619 14:46:59.623618   10746 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-w75jx-6657c7fddb-wdw6k" "namespace"="md-test" 
I0619 14:46:59.623664   10746 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-w75jx-6657c7fddb-wdw6k" "namespace"="md-test" 
... skipping 21 lines ...
I0619 14:46:59.860115   10746 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-w75jx-6657c7fddb-8mlr9" "namespace"="md-test" 
I0619 14:46:59.942604   10746 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-w75jx-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0619 14:46:59.942720   10746 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-w75jx-cdfc6fd6c" "namespace"="md-test" 
I0619 14:46:59.952972   10746 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-w75jx-cdfc6fd6c-pbjfb\"" "machineset"="md-w75jx-cdfc6fd6c" "namespace"="md-test" 
I0619 14:46:59.974943   10746 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-w75jx-cdfc6fd6c-pbjfb" "namespace"="md-test" 
I0619 14:46:59.974981   10746 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-w75jx-cdfc6fd6c-pbjfb" "namespace"="md-test" 
E0619 14:46:59.999487   10746 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"="md-w75jx-cdfc6fd6c-pbjfb" "namespace"="md-test" 
E0619 14:47:00.016655   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="the cache is not started, can not read objects" "controller"="machine" "name"="md-w75jx-cdfc6fd6c-pbjfb" "namespace"="md-test"
I0619 14:47:00.107349   10746 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-w75jx-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0619 14:47:00.107386   10746 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-w75jx-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0619 14:47:00.110615   10746 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-w75jx-6657c7fddb" "namespace"="md-test" "machine"="md-w75jx-6657c7fddb-bw4bf"
I0619 14:47:00.218673   10746 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-w75jx-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0619 14:47:00.218774   10746 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-w75jx-cdfc6fd6c" "namespace"="md-test" 
I0619 14:47:00.226722   10746 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-w75jx-cdfc6fd6c-bqvrt\"" "machineset"="md-w75jx-cdfc6fd6c" "namespace"="md-test" 
... skipping 14 lines ...
I0619 14:47:00.940807   10746 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-w75jx-cdfc6fd6c" "namespace"="md-test" "machine"="md-w75jx-cdfc6fd6c-bqvrt"
I0619 14:47:00.956427   10746 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-w75jx-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=2
I0619 14:47:00.956468   10746 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-w75jx-74d45c49c5" "namespace"="md-test" 
I0619 14:47:00.964858   10746 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-w75jx-74d45c49c5-v75kz\"" "machineset"="md-w75jx-74d45c49c5" "namespace"="md-test" 
I0619 14:47:01.030037   10746 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-jxfwq" "namespace"="default" "count"=1
I0619 14:47:01.030104   10746 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-jxfwq" "namespace"="default" "descendants"="Control plane machines: test6-7wng9" "indirect descendants count"=0
E0619 14:47:01.041174   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-w75jx-cdfc6fd6c-pbjfb\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-w75jx-cdfc6fd6c-pbjfb" "namespace"="md-test"
E0619 14:47:01.150504   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5gmxf: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5gmxf" "namespace"="default"
I0619 14:47:01.163328   10746 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-w75jx-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1
I0619 14:47:01.163362   10746 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-w75jx-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0619 14:47:01.168728   10746 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-w75jx-cdfc6fd6c" "namespace"="md-test" "machine"="md-w75jx-cdfc6fd6c-84zh2"
I0619 14:47:01.275562   10746 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-w75jx-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0619 14:47:01.275598   10746 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-w75jx-74d45c49c5" "namespace"="md-test" 
I0619 14:47:01.283982   10746 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-w75jx-74d45c49c5-xqvxc\"" "machineset"="md-w75jx-74d45c49c5" "namespace"="md-test" 
•

Ran 16 of 16 Specs in 26.845 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (26.84s)
PASS
Tearing down test suite
I0619 14:47:01.412471   10746 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
I0619 14:47:01.412480   10746 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I0619 14:47:01.412505   10746 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0619 14:47:01.412524   10746 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0619 14:47:01.412570   10746 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0619 14:47:01.412596   10746 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
I0619 14:47:01.412585   10746 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0619 14:47:01.414586   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinedeployments.cluster.x-k8s.io \"md-w75jx\" not found" "controller"="machinedeployment" "name"="md-w75jx" "namespace"="md-test"
E0619 14:47:01.414824   10746 machineset_controller.go:151] controllers/MachineSet "msg"="Failed to reconcile MachineSet" "error"="failed to retrieve InfrastructureMachineTemplate external object \"md-test\"/\"md-template\": Get http://127.0.0.1:41383/apis/infrastructure.cluster.x-k8s.io/v1alpha3/namespaces/md-test/infrastructuremachinetemplates/md-template: dial tcp 127.0.0.1:41383: connect: connection refused" "machineset"="md-w75jx-cdfc6fd6c" "namespace"="md-test" 
E0619 14:47:01.414899   10746 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to retrieve InfrastructureMachineTemplate external object \"md-test\"/\"md-template\": Get http://127.0.0.1:41383/apis/infrastructure.cluster.x-k8s.io/v1alpha3/namespaces/md-test/infrastructuremachinetemplates/md-template: dial tcp 127.0.0.1:41383: connect: connection refused" "controller"="machineset" "name"="md-w75jx-cdfc6fd6c" "namespace"="md-test"
E0619 14:47:01.417893   10746 event.go:272] Unable to write event: 'Post http://127.0.0.1:41383/api/v1/namespaces/md-test/events: dial tcp 127.0.0.1:41383: connect: connection refused' (may retry after sleeping)
E0619 14:47:01.446447   10746 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:41383/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1294&timeout=10s&timeoutSeconds=519&watch=true: dial tcp 127.0.0.1:41383: connect: connection refused
E0619 14:47:01.446601   10746 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:41383/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1294&timeout=10s&timeoutSeconds=540&watch=true: dial tcp 127.0.0.1:41383: connect: connection refused
E0619 14:47:01.448159   10746 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:41383/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1294&timeout=10s&timeoutSeconds=354&watch=true: dial tcp 127.0.0.1:41383: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	81.540s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 260 lines ...
I0619 14:45:51.239246   10983 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0619 14:45:51.240411   10983 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=37735
I0619 14:45:51.260661   10983 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}}}
I0619 14:45:51.361500   10983 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="cluster" 
I0619 14:45:51.361545   10983 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
•I0619 14:45:51.604544   10983 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
E0619 14:45:53.632700   10983 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-sbp47/test-cluster"
•E0619 14:45:54.075233   10983 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-hxj4z/test-cluster"
•E0619 14:45:54.639425   10983 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:33317/?timeout=50ms: dial tcp 127.0.0.1:33317: connect: connection refused"  "cluster"="cluster-cache-test-rngk4/test-cluster"
•I0619 14:45:54.878743   10983 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"clusterName":"","selector":{},"template":{"metadata":{},"spec":{"clusterName":"","bootstrap":{},"infrastructureRef":{}}}},"status":{}}}
I0619 14:45:55.079366   10983 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0619 14:45:55.079431   10983 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0619 14:45:55.079527   10983 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0619 14:45:55.612024   10983 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0619 14:45:55.612329   10983 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
E0619 14:45:55.706936   10983 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:45839/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=146&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:45839: connect: connection refused


Ran 5 of 5 Specs in 14.929 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (14.93s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	15.073s
?   	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
I0619 14:46:03.762911   11645 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
E0619 14:46:03.764126   11645 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
I0619 14:46:03.764727   11645 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I0619 14:46:03.764870   11645 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
I0619 14:46:19.832955   11645 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
I0619 14:46:19.833031   11645 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: 1655649951
Will run 1 of 1 specs

E0619 14:46:19.850350   11645 controller.go:126]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="Cluster.cluster.x-k8s.io \"kcp-foo-i1p3su\" not found" "kubeadmControlPlane"="kcp-foo-i1p3su" "namespace"="test" 
•

Ran 1 of 1 Specs in 0.015 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (0.02s)
=== RUN   TestKubeadmControlPlaneReconciler_upgradeControlPlane
I0619 14:46:19.851703   11645 controller.go:246]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-298r6c" "kubeadmControlPlane"="kcp-foo-298r6c" "namespace"="test" 
I0619 14:46:21.255077   11645 controller.go:331]  "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-298r6c" "kubeadmControlPlane"="kcp-foo-298r6c" "namespace"="test" "needRollout"=["kcp-foo-298r6c-p6cp6"]
I0619 14:46:21.255357   11645 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-298r6c" "kubeadmControlPlane"="kcp-foo-298r6c" "namespace"="test" "failures"="[machine kcp-foo-298r6c-s8pr4 does not have APIServerPodHealthy condition, machine kcp-foo-298r6c-s8pr4 does not have ControllerManagerPodHealthy condition, machine kcp-foo-298r6c-s8pr4 does not have SchedulerPodHealthy condition, machine kcp-foo-298r6c-s8pr4 does not have EtcdPodHealthy condition, machine kcp-foo-298r6c-s8pr4 does not have EtcdMemberHealthy condition]"
--- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (1.41s)
PASS
I0619 14:46:21.256380   11645 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0619 14:46:21.256463   11645 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0619 14:46:21.256497   11645 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-586250213/tls.crt: no such file or directory"  
E0619 14:46:21.256517   11645 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0619 14:46:21.256535   11645 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-586250213/tls.crt: no such file or directory"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers	30.220s
I0619 14:46:01.508350   11593 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"
I0619 14:46:01.508848   11593 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster"
I0619 14:46:01.508950   11593 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"
I0619 14:46:01.509007   11593 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster"
I0619 14:46:01.509142   11593 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: 1655649949
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: 1655649949
Will run 7 of 7 specs

•••••••
Ran 7 of 7 Specs in 0.001 seconds
SUCCESS! -- 7 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestMachineCollection (0.00s)
=== RUN   TestUpdateEtcdConditions
=== RUN   TestUpdateEtcdConditions/if_list_nodes_return_an_error_should_report_all_the_conditions_Unknown
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_be_ignored_if_there_are_provisioning_machines
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_report_a_problem_at_KCP_level_if_there_are_no_provisioning_machines
=== RUN   TestUpdateEtcdConditions/failure_creating_the_etcd_client_should_report_unknown_condition
... skipping 297 lines ...
    --- PASS: TestUpdateKubeProxyImageInfo/returns_error_if_image_repository_is_invalid (0.00s)
    --- PASS: TestUpdateKubeProxyImageInfo/does_not_update_image_repository_when_no_kube-proxy_update_is_requested (0.00s)
=== RUN   TestRemoveMachineFromKubeadmConfigMap
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_find_kubeadm-config_for_Kubernetes_version_<_1.22.0
E0619 14:46:03.280098   11593 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"  
E0619 14:46:11.603475   11593 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"  
E0619 14:46:20.589636   11593 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"  
E0619 14:46:31.719904   11593 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"  
E0619 14:46:48.193057   11593 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"  
E0619 14:47:01.201573   11593 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"  
E0619 14:47:18.848960   11593 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"  
E0619 14:47:39.772244   11593 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"  
E0619 14:48:10.788776   11593 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"  
E0619 14:48:55.945937   11593 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
E0619 14:48:55.955704   11593 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0619 14:48:55.955755   11593 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-519689892/tls.crt: no such file or directory"  
E0619 14:48:55.955776   11593 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0619 14:48:55.955794   11593 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-519689892/tls.crt: no such file or directory"  
I0619 14:48:55.955905   11593 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/internal	186.137s
=== RUN   TestEtcdMembers_WithErrors
--- PASS: TestEtcdMembers_WithErrors (0.00s)
=== RUN   TestEtcdMembers_WithSuccess
--- PASS: TestEtcdMembers_WithSuccess (0.00s)
... skipping 288 lines ...
I0619 14:46:12.605621   11941 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourcesetbinding" 
I0619 14:46:12.706243   11941 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0619 14:46:12.806748   11941 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0619 14:46:12.806822   11941 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0619 14:46:12.807292   11941 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0619 14:46:12.886666   11941 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-6ahkto"} 
E0619 14:46:12.909165   11941 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"
•I0619 14:46:13.966773   11941 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-8newki"} 
E0619 14:46:13.972633   11941 clusterresourceset_controller.go:257]  "msg"="failed to patch config" "error"="clusterresourcesetbindings.addons.cluster.x-k8s.io \"cluster-8newki\" not found"  
•E0619 14:46:13.997129   11941 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"
E0619 14:46:15.087602   11941 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get data field from the resource" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
E0619 14:46:16.112962   11941 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"
•E0619 14:46:17.237021   11941 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"
E0619 14:46:18.259896   11941 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"
•E0619 14:46:19.288493   11941 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"
•I0619 14:46:19.289194   11941 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0619 14:46:19.289220   11941 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
I0619 14:46:19.289260   11941 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
I0619 14:46:19.289288   11941 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 
E0619 14:46:19.289291   11941 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-296970929/tls.crt: no such file or directory"  
E0619 14:46:19.289359   11941 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0619 14:46:19.289396   11941 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-296970929/tls.crt: no such file or directory"  


Ran 5 of 5 Specs in 20.161 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (20.16s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/addons/controllers	20.214s
?   	sigs.k8s.io/cluster-api/exp/addons/controllers/predicates	[no test files]
=== RUN   TestMachinePoolDefault
=== RUN   TestMachinePoolDefault/for_MachinePool
... skipping 61 lines ...
    --- PASS: TestReconcileMachinePoolBootstrap/new_machinepool,_no_bootstrap_config_or_data (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_data_should_not_change (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_provider_is_to_not_ready (0.00s)
=== RUN   TestReconcileMachinePoolInfrastructure
=== RUN   TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready
=== RUN   TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed
E0619 14:46:03.047206   12080 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 96 lines ...
I0619 14:46:15.288330   12080 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0619 14:46:15.332586   12080 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••I0619 14:46:15.336415   12080 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


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

    Expected success, but got an error:
        <errors.aggregate | len:1, cap:1>: [
            {
                ErrStatus: {
                    TypeMeta: {Kind: "", APIVersion: ""},
                    ListMeta: {
                        SelfLink: "",
... skipping 24 lines ...
STEP: Creating a new patch helper
STEP: Updating the object spec
STEP: Updating the object status
STEP: Setting Ready condition
STEP: Patching the object
•I0619 14:46:39.708362   15121 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0619 14:46:39.708378   15121 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0619 14:46:39.708432   15121 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-115391123/tls.crt: no such file or directory"  



Summarizing 1 Failure:

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

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