This job view page is being replaced by Spyglass soon. Check out the new job view.
PRsbueringer: ✨ v0.3.x: KCP: block mgmt cluster updates to v1.22.0
ResultFAILURE
Tests 0 failed / 0 succeeded
Started2021-07-26 15:30
Elapsed4m25s
Revision0ea76dfd28bec8f5ad0cf2d96e3731b656540ba3
Refs 5013

No Test Failures!


Error lines from build-log.txt

... skipping 777 lines ...
I0726 15:32:08.913011    8396 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0726 15:32:08.913675    8396 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0726 15:32:08.924577    8396 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0726 15:32:08.927006    8396 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=39801
I0726 15:32:08.927015    8396 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0726 15:32:09.530720    8396 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" 
•E0726 15:32:09.545789    8396 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0726 15:32:09.545863    8396 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-308178512/tls.crt: no such file or directory"  
E0726 15:32:09.545894    8396 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0726 15:32:09.545923    8396 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-308178512/tls.crt: no such file or directory"  
I0726 15:32:09.545968    8396 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 1 of 1 Specs in 12.378 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (12.38s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	62.104s
=== RUN   TestNewInitControlPlaneAdditionalFileEncodings
--- PASS: TestNewInitControlPlaneAdditionalFileEncodings (0.00s)
=== RUN   TestNewInitControlPlaneCommands
... skipping 310 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 1389 lines ...
I0726 15:31:42.743728   10578 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machineset" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"clusterName":"","bootstrap":{},"infrastructureRef":{}},"status":{"bootstrapReady":false,"infrastructureReady":false}}}
I0726 15:31:42.743770   10578 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machineset" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}
I0726 15:31:42.743782   10578 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":{}}}
I0726 15:31:42.743797   10578 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machineset" 
I0726 15:31:42.743845   10578 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}
I0726 15:31:42.743873   10578 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
2021/07/26 15:31:42 http: TLS handshake error from 127.0.0.1:34366: EOF
=== RUN   TestClusterReconcilePhases
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infrastructure_ref_is_nil
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_error_if_unable_to_reconcile_infrastructure_ref
I0726 15:31:42.841205   10578 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"
I0726 15:31:42.845294   10578 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
... skipping 114 lines ...
    --- PASS: TestReconcileBootstrap/existing_machine,_machineset_owner_and_version_v1alpha2,_and_ownerref_updated (0.00s)
=== RUN   TestReconcileInfrastructure
=== RUN   TestReconcileInfrastructure/new_machine,_infrastructure_config_ready
I0726 15:31:42.882545   10578 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
I0726 15:31:42.884232   10578 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"
E0726 15:31:42.884505   10578 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
I0726 15:31:42.884838   10578 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
I0726 15:31:43.224185   10578 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0726 15:31:43.226388   10578 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0726 15:31:43.232486   10578 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-wm75h" "namespace"="test-machine-watches-blkgj" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0726 15:31:43.232565   10578 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0726 15:31:43.341051   10578 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-wm75h" "namespace"="test-machine-watches-blkgj" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0726 15:31:43.341171   10578 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0726 15:31:43.441655   10578 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-wm75h" "namespace"="test-machine-watches-blkgj" "noderef"="node-1"
E0726 15:31:43.451944   10578 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0726 15:31:43.451982   10578 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0726 15:31:43.491658   10578 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-wm75h\" in namespace \"test-machine-watches-blkgj\", requeuing: requeue in 1s"  
E0726 15:31:43.503418   10578 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-wm75h\" in namespace \"test-machine-watches-blkgj\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-wm75h\" in namespace \"test-machine-watches-blkgj\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-wm75h" "namespace"="test-machine-watches-blkgj"
--- PASS: TestWatches (0.64s)
=== 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
I0726 15:31:43.727204   10578 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-2pfsf" "namespace"="test-machine-watches-blkgj" "count"=1
I0726 15:31:43.727270   10578 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-2pfsf" "namespace"="test-machine-watches-blkgj" "descendants"="Worker machines: machine-created-wm75h" "indirect descendants count"=0
I0726 15:31:43.742100   10578 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-2pfsf" "namespace"="test-machine-watches-blkgj" "count"=1
I0726 15:31:43.742180   10578 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-2pfsf" "namespace"="test-machine-watches-blkgj" "descendants"="Worker machines: machine-created-wm75h" "indirect descendants count"=0
I0726 15:31:44.503986   10578 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-2pfsf" "machine"="machine-created-wm75h" "namespace"="test-machine-watches-blkgj" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"aa560488-d716-42c9-aa60-78c9bf93f7c9","apiVersion":"v1"}
E0726 15:31:44.556567   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-wm75h\" not found" "controller"="machine" "name"="machine-created-wm75h" "namespace"="test-machine-watches-blkgj"
E0726 15:31:45.613423   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-jdmvj\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-4x8jm\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-4x8jm: secrets \"machine-reconcile-4x8jm-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-jdmvj" "namespace"="default"
I0726 15:31:46.615179   10578 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-4x8jm" "machine"="machine-created-jdmvj" "namespace"="default" "cause"="noderef is nil" "node"=null
I0726 15:31:46.651463   10578 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-4x8jm" "machine"="machine-created-jdmvj" "namespace"="default" "cause"="noderef is nil" "node"=null
I0726 15:31:46.674405   10578 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-4x8jm" "machine"="machine-created-jdmvj" "namespace"="default" "cause"="noderef is nil" "node"=null
E0726 15:31:46.719938   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-jdmvj\" not found" "controller"="machine" "name"="machine-created-jdmvj" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.20s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.20s)
=== RUN   TestMachineFinalizer
=== RUN   TestMachineFinalizer/should_add_a_machine_finalizer_to_the_machine_if_it_doesn't_have_one
=== RUN   TestMachineFinalizer/should_append_the_machine_finalizer_to_the_machine_if_it_already_has_a_finalizer
--- PASS: TestMachineFinalizer (0.00s)
... skipping 25 lines ...
    --- PASS: TestReconcileRequest/machine_should_be_updated (0.00s)
    --- PASS: TestReconcileRequest/machine_should_be_deleted (0.01s)
=== RUN   TestMachineConditions
=== RUN   TestMachineConditions/all_conditions_true
I0726 15:31:46.776541   10578 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="blah" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0726 15:31:46.780512   10578 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="blah" "namespace"="default" "err"="cannot create a metadata client without a rest config"
E0726 15:31:46.790137   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-4x8jm\" not found" "controller"="cluster" "name"="machine-reconcile-4x8jm" "namespace"="default"
=== RUN   TestMachineConditions/infra_condition_consumes_reason_from_the_infra_config
I0726 15:31:46.793705   10578 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="blah" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0726 15:31:46.795295   10578 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="blah" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0726 15:31:46.829985   10578 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="blah" "namespace"="default" 
=== RUN   TestMachineConditions/infra_condition_consumes_the_fallback_reason
I0726 15:31:46.849393   10578 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="blah" "namespace"="default" "err"="cannot create a metadata client without a rest config"
... skipping 100 lines ...
    --- PASS: TestMachineDeploymentSyncStatus/machine_set_failed (0.00s)
=== RUN   TestMachineHealthCheck_Reconcile
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist
I0726 15:31:46.949889   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d7hvg" "namespace"="test-mhc-wbkqr" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
I0726 15:31:46.994949   10578 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0726 15:31:46.996112   10578 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-2nmpb\" not found"  "cluster"="test-mhc-wbkqr/test-cluster-2nmpb"
E0726 15:31:47.002785   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-d7hvg\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-d7hvg\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-d7hvg" "namespace"="test-mhc-wbkqr"
=== 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
I0726 15:31:48.003104   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gkb64" "namespace"="test-mhc-h6txp" 
I0726 15:31:48.003233   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d7hvg" "namespace"="test-mhc-wbkqr" 
I0726 15:31:48.003267   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7zk2d" "namespace"="test-mhc-gv4cm" 
I0726 15:31:48.003306   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rt8vd" "namespace"="test-mhc-xkmpf" 
I0726 15:31:48.027560   10578 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0726 15:31:48.149180   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rt8vd" "namespace"="test-mhc-xkmpf" 
I0726 15:31:48.154007   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rt8vd" "namespace"="test-mhc-xkmpf" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
I0726 15:31:48.168782   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-rt8vd" "namespace"="test-mhc-xkmpf" 
E0726 15:31:48.184716   10578 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-xkmpf/test-cluster-cqm6v"
E0726 15:31:48.188940   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-cqm6v\" not found" "controller"="cluster" "name"="test-cluster-cqm6v" "namespace"="test-mhc-xkmpf"
I0726 15:31:48.198538   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lssfr" "namespace"="test-mhc-6jd7q" 
I0726 15:31:48.211502   10578 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0726 15:31:48.229770   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lssfr" "namespace"="test-mhc-6jd7q" 
I0726 15:31:48.234269   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lssfr" "namespace"="test-mhc-6jd7q" 
E0726 15:31:48.304349   10578 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-6jd7q/test-cluster-7lbmf"
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0726 15:31:48.309355   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lssfr" "namespace"="test-mhc-6jd7q" 
I0726 15:31:48.434044   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fsmw5" "namespace"="test-mhc-lws89" 
inframachine created: test-mhc-machine-infra-zzgkb
I0726 15:31:48.465154   10578 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-wjvf4
I0726 15:31:48.567225   10578 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-lws89/test-mhc-fsmw5/test-mhc-machine-wjvf4/"
node created: test-mhc-node-sn6cg
E0726 15:31:48.576864   10578 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-sn6cg, got []"  "node"="test-mhc-node-sn6cg"
E0726 15:31:48.577088   10578 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-sn6cg"
I0726 15:31:48.596481   10578 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-wjvf4" "namespace"="test-mhc-lws89" "noderef"="test-mhc-node-sn6cg"
inframachine created: test-mhc-machine-infra-xtscm
machine created: test-mhc-machine-zmv8v
E0726 15:31:48.713874   10578 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-9p8pv, got []"  "node"="test-mhc-node-9p8pv"
node created: test-mhc-node-9p8pv
E0726 15:31:48.714645   10578 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-9p8pv"
I0726 15:31:48.740528   10578 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-zmv8v" "namespace"="test-mhc-lws89" "noderef"="test-mhc-node-9p8pv"
I0726 15:31:48.780751   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fsmw5" "namespace"="test-mhc-lws89" 
I0726 15:31:48.836447   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fsmw5" "namespace"="test-mhc-lws89" 
Cleaning up nodes, machines and infra machines.
I0726 15:31:48.848820   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fsmw5" "namespace"="test-mhc-lws89" 
I0726 15:31:48.849246   10578 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-lws89/test-mhc-fsmw5/test-mhc-machine-wjvf4/"
I0726 15:31:48.883850   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fsmw5" "namespace"="test-mhc-lws89" 
I0726 15:31:48.887222   10578 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-lws89/test-mhc-fsmw5/test-mhc-machine-wjvf4/"
I0726 15:31:48.889807   10578 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-lws89/test-mhc-fsmw5/test-mhc-machine-zmv8v/"
E0726 15:31:48.909617   10578 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-lws89/test-cluster-4nlcb"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
E0726 15:31:48.927553   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-fsmw5\" not found" "controller"="machinehealthcheck" "name"="test-mhc-fsmw5" "namespace"="test-mhc-lws89"
inframachine created: test-mhc-machine-infra-m2t7b
E0726 15:31:49.050509   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"test-mhc-machine-wjvf4\" in namespace \"test-mhc-lws89\": cannot find node with matching ProviderID" "controller"="machine" "name"="test-mhc-machine-wjvf4" "namespace"="test-mhc-lws89"
machine created: test-mhc-machine-r67lf
E0726 15:31:49.210000   10578 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-blkgj/machine-reconcile-2pfsf"
I0726 15:31:49.927856   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fsmw5" "namespace"="test-mhc-lws89" 
I0726 15:31:49.927970   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:49.943024   10578 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0726 15:31:50.050824   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4nlcb\" for machine \"test-mhc-machine-zmv8v\" in namespace \"test-mhc-lws89\": Cluster.cluster.x-k8s.io \"test-cluster-4nlcb\" not found" "controller"="machine" "name"="test-mhc-machine-zmv8v" "namespace"="test-mhc-lws89"
I0726 15:31:50.066559   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:50.067794   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:50.069521   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:50.077392   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:50.079285   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:50.081302   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
... skipping 430 lines ...
I0726 15:31:51.038933   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:51.041750   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:51.043594   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:51.045737   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:51.047565   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:51.049453   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
E0726 15:31:51.051394   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4nlcb\" for machine \"test-mhc-machine-wjvf4\" in namespace \"test-mhc-lws89\": Cluster.cluster.x-k8s.io \"test-cluster-4nlcb\" not found" "controller"="machine" "name"="test-mhc-machine-wjvf4" "namespace"="test-mhc-lws89"
I0726 15:31:51.051687   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:51.053442   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:51.055198   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:51.056973   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:51.058783   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:51.060537   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
... skipping 469 lines ...
I0726 15:31:52.054275   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:52.057374   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:52.062094   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:52.064691   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:52.067726   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:52.069874   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
E0726 15:31:52.072036   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4nlcb\" for machine \"test-mhc-machine-zmv8v\" in namespace \"test-mhc-lws89\": Cluster.cluster.x-k8s.io \"test-cluster-4nlcb\" not found" "controller"="machine" "name"="test-mhc-machine-zmv8v" "namespace"="test-mhc-lws89"
node created: test-mhc-node-ld8td
E0726 15:31:52.079965   10578 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-ld8td, got []"  "node"="test-mhc-node-ld8td"
I0726 15:31:52.089880   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
inframachine created: test-mhc-machine-infra-ct42p
machine created: test-mhc-machine-xgg46
I0726 15:31:52.122903   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:52.150255   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:52.160543   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
... skipping 340 lines ...
I0726 15:31:53.061223   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:53.063187   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:53.065150   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:53.067136   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:53.069126   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:53.071112   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
E0726 15:31:53.072371   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4nlcb\" for machine \"test-mhc-machine-wjvf4\" in namespace \"test-mhc-lws89\": Cluster.cluster.x-k8s.io \"test-cluster-4nlcb\" not found" "controller"="machine" "name"="test-mhc-machine-wjvf4" "namespace"="test-mhc-lws89"
I0726 15:31:53.073061   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:53.075062   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:53.077030   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:53.085401   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:53.087550   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:53.089584   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
... skipping 345 lines ...
I0726 15:31:54.098866   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:54.100142   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:54.101976   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:54.103174   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:54.104152   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:54.110138   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
E0726 15:31:54.111383   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4nlcb\" for machine \"test-mhc-machine-zmv8v\" in namespace \"test-mhc-lws89\": Cluster.cluster.x-k8s.io \"test-cluster-4nlcb\" not found" "controller"="machine" "name"="test-mhc-machine-zmv8v" "namespace"="test-mhc-lws89"
I0726 15:31:54.112312   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:54.113396   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:54.115623   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:54.122863   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:54.125132   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:54.127318   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
... skipping 308 lines ...
I0726 15:31:55.125607   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:55.127827   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:55.129658   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:55.130836   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:55.132431   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:55.133919   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:55.134332   10578 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-fflqz/test-mhc-cw9dd/test-mhc-machine-xgg46/"
E0726 15:31:55.135051   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4nlcb\" for machine \"test-mhc-machine-wjvf4\" in namespace \"test-mhc-lws89\": Cluster.cluster.x-k8s.io \"test-cluster-4nlcb\" not found" "controller"="machine" "name"="test-mhc-machine-wjvf4" "namespace"="test-mhc-lws89"
E0726 15:31:55.142195   10578 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-ldj9v, got []"  "node"="test-mhc-node-ldj9v"
node created: test-mhc-node-ldj9v
I0726 15:31:55.155833   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:55.156337   10578 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-fflqz/test-mhc-cw9dd/test-mhc-machine-xgg46/"
I0726 15:31:55.168424   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
inframachine created: test-mhc-machine-infra-kmvwv
machine created: test-mhc-machine-l7t6g
I0726 15:31:55.198215   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:55.206686   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:55.208280   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
... skipping 287 lines ...
I0726 15:31:56.131165   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:56.133628   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:56.136523   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:56.145021   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:56.148672   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:56.151183   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
E0726 15:31:56.153724   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4nlcb\" for machine \"test-mhc-machine-zmv8v\" in namespace \"test-mhc-lws89\": Cluster.cluster.x-k8s.io \"test-cluster-4nlcb\" not found" "controller"="machine" "name"="test-mhc-machine-zmv8v" "namespace"="test-mhc-lws89"
I0726 15:31:56.154802   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:56.156537   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:56.158412   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:56.160121   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:56.161643   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:56.163144   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
... skipping 309 lines ...
I0726 15:31:57.181289   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:57.183701   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:57.186214   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:57.188686   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:57.197885   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:57.199951   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
E0726 15:31:57.200129   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4nlcb\" for machine \"test-mhc-machine-wjvf4\" in namespace \"test-mhc-lws89\": Cluster.cluster.x-k8s.io \"test-cluster-4nlcb\" not found" "controller"="machine" "name"="test-mhc-machine-wjvf4" "namespace"="test-mhc-lws89"
I0726 15:31:57.202795   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:57.204392   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:57.205915   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:57.207521   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:57.209051   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:57.210882   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
... skipping 285 lines ...
I0726 15:31:58.200509   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:58.203860   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:58.208508   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:58.212528   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:58.217177   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:58.218691   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:58.219141   10578 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-fflqz/test-mhc-cw9dd/test-mhc-machine-l7t6g/"
E0726 15:31:58.227698   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4nlcb\" for machine \"test-mhc-machine-zmv8v\" in namespace \"test-mhc-lws89\": Cluster.cluster.x-k8s.io \"test-cluster-4nlcb\" not found" "controller"="machine" "name"="test-mhc-machine-zmv8v" "namespace"="test-mhc-lws89"
I0726 15:31:58.230971   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:58.231477   10578 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-fflqz/test-mhc-cw9dd/test-mhc-machine-l7t6g/"
node created: test-mhc-node-lzt5z
E0726 15:31:58.253709   10578 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-lzt5z, got []"  "node"="test-mhc-node-lzt5z"
I0726 15:31:58.260998   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
Cleaning up nodes, machines and infra machines.
I0726 15:31:58.261672   10578 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-fflqz/test-mhc-cw9dd/test-mhc-machine-l7t6g/test-mhc-node-lzt5z"
I0726 15:31:58.278358   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
Cleaning up nodes, machines and infra machines.
I0726 15:31:58.281153   10578 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-fflqz/test-mhc-cw9dd/test-mhc-machine-l7t6g/"
I0726 15:31:58.299298   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:58.299839   10578 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-fflqz/test-mhc-cw9dd/test-mhc-machine-r67lf/"
I0726 15:31:58.321898   10578 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-fflqz/test-mhc-cw9dd/test-mhc-machine-xgg46/"
I0726 15:31:58.343641   10578 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-59dks" "namespace"="test-mhc-fflqz" "count"=2
I0726 15:31:58.343727   10578 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-59dks" "namespace"="test-mhc-fflqz" "descendants"="Worker machines: test-mhc-machine-xgg46,test-mhc-machine-l7t6g,test-mhc-machine-r67lf" "indirect descendants count"=1
I0726 15:31:58.347851   10578 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-fflqz/test-mhc-cw9dd/test-mhc-machine-l7t6g/"
I0726 15:31:58.349800   10578 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-59dks" "namespace"="test-mhc-fflqz" "count"=2
I0726 15:31:58.349860   10578 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-59dks" "namespace"="test-mhc-fflqz" "descendants"="Worker machines: test-mhc-machine-r67lf,test-mhc-machine-xgg46,test-mhc-machine-l7t6g" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
E0726 15:31:58.355823   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-cw9dd\" not found" "controller"="machinehealthcheck" "name"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz"
inframachine created: test-mhc-machine-infra-bcmdd
machine created: test-mhc-machine-fdcbh
I0726 15:31:59.228392   10578 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-59dks" "machine"="test-mhc-machine-xgg46" "namespace"="test-mhc-fflqz" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-ldj9v"}
E0726 15:31:59.297046   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-xgg46\" not found" "controller"="machine" "name"="test-mhc-machine-xgg46" "namespace"="test-mhc-fflqz"
I0726 15:31:59.356288   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cw9dd" "namespace"="test-mhc-fflqz" 
I0726 15:31:59.356382   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:31:59.375256   10578 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0726 15:31:59.392844   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:31:59.394209   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:31:59.398018   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:31:59.438918   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:31:59.519921   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:31:59.680906   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:32:00.001946   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
E0726 15:32:00.297402   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4nlcb\" for machine \"test-mhc-machine-wjvf4\" in namespace \"test-mhc-lws89\": Cluster.cluster.x-k8s.io \"test-cluster-4nlcb\" not found" "controller"="machine" "name"="test-mhc-machine-wjvf4" "namespace"="test-mhc-lws89"
I0726 15:32:00.643008   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:32:01.297996   10578 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-59dks" "machine"="test-mhc-machine-l7t6g" "namespace"="test-mhc-fflqz" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-lzt5z"}
E0726 15:32:01.349961   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-l7t6g\" not found" "controller"="machine" "name"="test-mhc-machine-l7t6g" "namespace"="test-mhc-fflqz"
I0726 15:32:01.927515   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:32:02.353682   10578 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-59dks" "machine"="test-mhc-machine-r67lf" "namespace"="test-mhc-fflqz" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-ld8td"}
E0726 15:32:02.412316   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-r67lf\" not found" "controller"="machine" "name"="test-mhc-machine-r67lf" "namespace"="test-mhc-fflqz"
E0726 15:32:03.365978   10578 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-fflqz/test-cluster-59dks"
E0726 15:32:03.412775   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4nlcb\" for machine \"test-mhc-machine-zmv8v\" in namespace \"test-mhc-lws89\": Cluster.cluster.x-k8s.io \"test-cluster-4nlcb\" not found" "controller"="machine" "name"="test-mhc-machine-zmv8v" "namespace"="test-mhc-lws89"
I0726 15:32:04.421730   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
E0726 15:32:04.426050   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4nlcb\" for machine \"test-mhc-machine-wjvf4\" in namespace \"test-mhc-lws89\": Cluster.cluster.x-k8s.io \"test-cluster-4nlcb\" not found" "controller"="machine" "name"="test-mhc-machine-wjvf4" "namespace"="test-mhc-lws89"
I0726 15:32:04.426418   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:32:04.453119   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:32:04.488492   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
node created: test-mhc-node-vtpqb
E0726 15:32:04.524950   10578 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-vtpqb, got []"  "node"="test-mhc-node-vtpqb"
I0726 15:32:04.535005   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
inframachine created: test-mhc-machine-infra-skct5
machine created: test-mhc-machine-zpgbr
I0726 15:32:04.562789   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:32:04.703070   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:32:04.708441   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:32:04.731082   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:32:04.772528   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:32:04.853964   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:32:05.015302   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:32:05.336662   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
E0726 15:32:05.426677   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4nlcb\" for machine \"test-mhc-machine-zmv8v\" in namespace \"test-mhc-lws89\": Cluster.cluster.x-k8s.io \"test-cluster-4nlcb\" not found" "controller"="machine" "name"="test-mhc-machine-zmv8v" "namespace"="test-mhc-lws89"
I0726 15:32:05.980087   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:32:06.445424   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:32:06.464864   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:32:06.475601   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:32:06.482858   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:32:06.496004   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:32:06.499215   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
E0726 15:32:06.499660   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4nlcb\" for machine \"test-mhc-machine-wjvf4\" in namespace \"test-mhc-lws89\": Cluster.cluster.x-k8s.io \"test-cluster-4nlcb\" not found" "controller"="machine" "name"="test-mhc-machine-wjvf4" "namespace"="test-mhc-lws89"
I0726 15:32:06.544480   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
node created: test-mhc-node-ljnp9
E0726 15:32:06.573916   10578 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-ljnp9, got []"  "node"="test-mhc-node-ljnp9"
I0726 15:32:06.582319   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
inframachine created: test-mhc-machine-infra-9t5sd
I0726 15:32:06.594702   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:32:06.604121   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
machine created: test-mhc-machine-w5zwh
I0726 15:32:06.622624   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:32:07.263434   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
E0726 15:32:07.500104   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4nlcb\" for machine \"test-mhc-machine-zmv8v\" in namespace \"test-mhc-lws89\": Cluster.cluster.x-k8s.io \"test-cluster-4nlcb\" not found" "controller"="machine" "name"="test-mhc-machine-zmv8v" "namespace"="test-mhc-lws89"
I0726 15:32:08.516701   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:32:08.531030   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:32:08.539647   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:32:08.552833   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:32:08.567186   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:32:08.576178   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:32:08.578865   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
E0726 15:32:08.580299   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4nlcb\" for machine \"test-mhc-machine-wjvf4\" in namespace \"test-mhc-lws89\": Cluster.cluster.x-k8s.io \"test-cluster-4nlcb\" not found" "controller"="machine" "name"="test-mhc-machine-wjvf4" "namespace"="test-mhc-lws89"
I0726 15:32:08.618847   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
E0726 15:32:08.628492   10578 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-c928g, got []"  "node"="test-mhc-node-c928g"
node created: test-mhc-node-c928g
I0726 15:32:08.637704   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
Cleaning up nodes, machines and infra machines.
I0726 15:32:08.648913   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
Cleaning up nodes, machines and infra machines.
I0726 15:32:08.687115   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:32:08.714779   10578 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-pgs5t" "namespace"="test-mhc-mtvmn" "count"=2
I0726 15:32:08.714852   10578 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-pgs5t" "namespace"="test-mhc-mtvmn" "descendants"="Worker machines: test-mhc-machine-fdcbh,test-mhc-machine-zpgbr,test-mhc-machine-w5zwh" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_less_than_the_NodeStartupTimeout
E0726 15:32:08.721216   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-bfwj6\" not found" "controller"="machinehealthcheck" "name"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn"
I0726 15:32:08.723846   10578 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-pgs5t" "namespace"="test-mhc-mtvmn" "count"=2
I0726 15:32:08.723906   10578 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-pgs5t" "namespace"="test-mhc-mtvmn" "descendants"="Worker machines: test-mhc-machine-fdcbh,test-mhc-machine-zpgbr,test-mhc-machine-w5zwh" "indirect descendants count"=1
inframachine created: test-mhc-machine-infra-2msnk
machine created: test-mhc-machine-cwbvc
E0726 15:32:09.581821   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4nlcb\" for machine \"test-mhc-machine-zmv8v\" in namespace \"test-mhc-lws89\": Cluster.cluster.x-k8s.io \"test-cluster-4nlcb\" not found" "controller"="machine" "name"="test-mhc-machine-zmv8v" "namespace"="test-mhc-lws89"
I0726 15:32:09.721521   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bfwj6" "namespace"="test-mhc-mtvmn" 
I0726 15:32:09.721635   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pgcf6" "namespace"="test-mhc-tsvtk" 
I0726 15:32:09.756412   10578 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0726 15:32:09.777911   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pgcf6" "namespace"="test-mhc-tsvtk" 
I0726 15:32:10.582400   10578 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-pgs5t" "machine"="test-mhc-machine-fdcbh" "namespace"="test-mhc-mtvmn" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-vtpqb"}
E0726 15:32:10.636008   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-fdcbh\" not found" "controller"="machine" "name"="test-mhc-machine-fdcbh" "namespace"="test-mhc-mtvmn"
I0726 15:32:11.636644   10578 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-pgs5t" "machine"="test-mhc-machine-zpgbr" "namespace"="test-mhc-mtvmn" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-ljnp9"}
E0726 15:32:11.688638   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-zpgbr\" not found" "controller"="machine" "name"="test-mhc-machine-zpgbr" "namespace"="test-mhc-mtvmn"
I0726 15:32:12.689202   10578 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-pgs5t" "machine"="test-mhc-machine-w5zwh" "namespace"="test-mhc-mtvmn" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-c928g"}
E0726 15:32:12.736553   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-w5zwh\" not found" "controller"="machine" "name"="test-mhc-machine-w5zwh" "namespace"="test-mhc-mtvmn"
E0726 15:32:13.738232   10578 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-mtvmn/test-cluster-pgs5t"
I0726 15:32:13.746150   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pgcf6" "namespace"="test-mhc-tsvtk" 
I0726 15:32:13.750894   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pgcf6" "namespace"="test-mhc-tsvtk" 
E0726 15:32:13.751903   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4nlcb\" for machine \"test-mhc-machine-wjvf4\" in namespace \"test-mhc-lws89\": Cluster.cluster.x-k8s.io \"test-cluster-4nlcb\" not found" "controller"="machine" "name"="test-mhc-machine-wjvf4" "namespace"="test-mhc-lws89"
node created: test-mhc-node-g25p4
E0726 15:32:13.796670   10578 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-g25p4, got []"  "node"="test-mhc-node-g25p4"
I0726 15:32:13.804740   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pgcf6" "namespace"="test-mhc-tsvtk" 
inframachine created: test-mhc-machine-infra-b7lv6
machine created: test-mhc-machine-jtb2t
I0726 15:32:13.823843   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pgcf6" "namespace"="test-mhc-tsvtk" 
I0726 15:32:13.830612   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pgcf6" "namespace"="test-mhc-tsvtk" 
E0726 15:32:14.752359   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4nlcb\" for machine \"test-mhc-machine-zmv8v\" in namespace \"test-mhc-lws89\": Cluster.cluster.x-k8s.io \"test-cluster-4nlcb\" not found" "controller"="machine" "name"="test-mhc-machine-zmv8v" "namespace"="test-mhc-lws89"
I0726 15:32:15.777535   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pgcf6" "namespace"="test-mhc-tsvtk" 
I0726 15:32:15.788299   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pgcf6" "namespace"="test-mhc-tsvtk" 
I0726 15:32:15.802757   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pgcf6" "namespace"="test-mhc-tsvtk" 
I0726 15:32:15.808875   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pgcf6" "namespace"="test-mhc-tsvtk" 
I0726 15:32:15.823674   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pgcf6" "namespace"="test-mhc-tsvtk" 
I0726 15:32:15.828975   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pgcf6" "namespace"="test-mhc-tsvtk" 
I0726 15:32:15.840972   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pgcf6" "namespace"="test-mhc-tsvtk" 
node created: test-mhc-node-76f2z
E0726 15:32:15.849771   10578 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-76f2z, got []"  "node"="test-mhc-node-76f2z"
I0726 15:32:15.869042   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pgcf6" "namespace"="test-mhc-tsvtk" 
I0726 15:32:15.877416   10578 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-jtb2t" "namespace"="test-mhc-tsvtk" "noderef"="test-mhc-node-76f2z"
inframachine created: test-mhc-machine-infra-sq8kv
machine created: test-mhc-machine-4kj6c
I0726 15:32:15.897716   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pgcf6" "namespace"="test-mhc-tsvtk" 
I0726 15:32:15.913855   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pgcf6" "namespace"="test-mhc-tsvtk" 
... skipping 7 lines ...
I0726 15:32:16.092983   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pgcf6" "namespace"="test-mhc-tsvtk" 
I0726 15:32:16.100220   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pgcf6" "namespace"="test-mhc-tsvtk" 
I0726 15:32:16.109594   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pgcf6" "namespace"="test-mhc-tsvtk" 
Cleaning up nodes, machines and infra machines.
I0726 15:32:16.123487   10578 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-grlzz" "machine"="test-mhc-machine-4kj6c" "namespace"="test-mhc-tsvtk" "cause"="noderef is nil" "node"=null
I0726 15:32:16.125195   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pgcf6" "namespace"="test-mhc-tsvtk" 
I0726 15:32:16.125776   10578 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-tsvtk/test-mhc-pgcf6/test-mhc-machine-cwbvc/"
I0726 15:32:16.159851   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pgcf6" "namespace"="test-mhc-tsvtk" 
I0726 15:32:16.161946   10578 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-tsvtk/test-mhc-pgcf6/test-mhc-machine-cwbvc/"
I0726 15:32:16.162478   10578 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-tsvtk/test-mhc-pgcf6/test-mhc-machine-jtb2t/"
I0726 15:32:16.188971   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pgcf6" "namespace"="test-mhc-tsvtk" 
I0726 15:32:16.197080   10578 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-grlzz" "namespace"="test-mhc-tsvtk" "count"=3
I0726 15:32:16.197786   10578 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-tsvtk/test-mhc-pgcf6/test-mhc-machine-cwbvc/"
I0726 15:32:16.199168   10578 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-tsvtk/test-mhc-pgcf6/test-mhc-machine-jtb2t/"
I0726 15:32:16.200594   10578 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-grlzz" "namespace"="test-mhc-tsvtk" "descendants"="Worker machines: test-mhc-machine-cwbvc,test-mhc-machine-jtb2t,test-mhc-machine-4kj6c" "indirect descendants count"=0
I0726 15:32:16.215142   10578 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-grlzz" "namespace"="test-mhc-tsvtk" "count"=3
=== 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
I0726 15:32:16.216566   10578 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-grlzz" "namespace"="test-mhc-tsvtk" "descendants"="Worker machines: test-mhc-machine-cwbvc,test-mhc-machine-jtb2t,test-mhc-machine-4kj6c" "indirect descendants count"=0
I0726 15:32:16.215597   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pgcf6" "namespace"="test-mhc-tsvtk" 
I0726 15:32:16.217026   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pgcf6" "namespace"="test-mhc-tsvtk" 
E0726 15:32:16.220555   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-4kj6c\" not found" "controller"="machine" "name"="test-mhc-machine-4kj6c" "namespace"="test-mhc-tsvtk"
I0726 15:32:16.247930   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
inframachine created: test-mhc-machine-infra-gjl5v
I0726 15:32:16.263886   10578 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-dx98x
I0726 15:32:16.389145   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:16.390163   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
... skipping 419 lines ...
I0726 15:32:17.273395   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:17.275449   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:17.277287   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:17.279447   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:17.281316   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:17.283143   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
E0726 15:32:17.284433   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-cwbvc\" not found" "controller"="machine" "name"="test-mhc-machine-cwbvc" "namespace"="test-mhc-tsvtk"
I0726 15:32:17.284988   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:17.286826   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:17.288660   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:17.290489   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:17.292257   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:17.293991   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
... skipping 472 lines ...
I0726 15:32:18.325087   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:18.326894   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:18.328572   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:18.330479   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:18.333200   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:18.337372   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
E0726 15:32:18.338772   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-jtb2t\" not found" "controller"="machine" "name"="test-mhc-machine-jtb2t" "namespace"="test-mhc-tsvtk"
I0726 15:32:18.339208   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:18.340968   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:18.342966   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:18.344765   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:18.346512   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:18.348328   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
... skipping 453 lines ...
I0726 15:32:19.343655   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:19.345714   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:19.347290   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:19.348336   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:19.349457   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:19.350628   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
E0726 15:32:19.351043   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4nlcb\" for machine \"test-mhc-machine-wjvf4\" in namespace \"test-mhc-lws89\": Cluster.cluster.x-k8s.io \"test-cluster-4nlcb\" not found" "controller"="machine" "name"="test-mhc-machine-wjvf4" "namespace"="test-mhc-lws89"
I0726 15:32:19.351743   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:19.352179   10578 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-lls7z/test-mhc-2gqbh/test-mhc-machine-dx98x/"
I0726 15:32:19.362743   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:19.363032   10578 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-lls7z/test-mhc-2gqbh/test-mhc-machine-dx98x/"
E0726 15:32:19.390246   10578 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-hmq4g, got []"  "node"="test-mhc-node-hmq4g"
node created: test-mhc-node-hmq4g
E0726 15:32:19.391082   10578 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-hmq4g, got []"  "node"="test-mhc-node-hmq4g"
I0726 15:32:19.421769   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:19.469675   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:19.480974   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:19.481384   10578 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-lls7z/test-mhc-2gqbh/test-mhc-machine-dx98x/test-mhc-node-hmq4g"
I0726 15:32:19.502283   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:19.502702   10578 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-lls7z/test-mhc-2gqbh/test-mhc-machine-dx98x/test-mhc-node-hmq4g"
I0726 15:32:19.508090   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:19.508524   10578 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-lls7z/test-mhc-2gqbh/test-mhc-machine-dx98x/test-mhc-node-hmq4g"
Cleaning up nodes, machines and infra machines.
I0726 15:32:19.514009   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:19.514386   10578 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-lls7z/test-mhc-2gqbh/test-mhc-machine-dx98x/"
I0726 15:32:19.531748   10578 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-7mlzh" "namespace"="test-mhc-lls7z" "descendants"="Worker machines: test-mhc-machine-dx98x" "indirect descendants count"=1
I0726 15:32:19.537501   10578 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-7mlzh" "namespace"="test-mhc-lls7z" "descendants"="Worker machines: test-mhc-machine-dx98x" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0726 15:32:19.542084   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2gqbh" "namespace"="test-mhc-lls7z" 
I0726 15:32:19.652480   10578 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-mf82f" "namespace"="test-mhc-fjk6b" "creating"=1 "need"=1
I0726 15:32:19.652535   10578 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-mf82f" "namespace"="test-mhc-fjk6b" 
I0726 15:32:19.666711   10578 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-mf82f-h5h7f\"" "machineset"="mhc-ms-mf82f" "namespace"="test-mhc-fjk6b" 
I0726 15:32:19.737960   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7g4tt" "namespace"="test-mhc-fjk6b" 
I0726 15:32:19.752814   10578 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0726 15:32:19.871749   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7g4tt" "namespace"="test-mhc-fjk6b" 
E0726 15:32:20.351588   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4nlcb\" for machine \"test-mhc-machine-zmv8v\" in namespace \"test-mhc-lws89\": Cluster.cluster.x-k8s.io \"test-cluster-4nlcb\" not found" "controller"="machine" "name"="test-mhc-machine-zmv8v" "namespace"="test-mhc-lws89"
I0726 15:32:20.871935   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7g4tt" "namespace"="test-mhc-fjk6b" 
E0726 15:32:21.228790   10578 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-tsvtk/test-cluster-grlzz"
I0726 15:32:21.352211   10578 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-7mlzh" "machine"="test-mhc-machine-dx98x" "namespace"="test-mhc-lls7z" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-hmq4g"}
E0726 15:32:21.421093   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-dx98x\" not found" "controller"="machine" "name"="test-mhc-machine-dx98x" "namespace"="test-mhc-lls7z"
I0726 15:32:21.873029   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7g4tt" "namespace"="test-mhc-fjk6b" 
I0726 15:32:22.430345   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7g4tt" "namespace"="test-mhc-fjk6b" 
I0726 15:32:22.430975   10578 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-mf82f" "namespace"="test-mhc-fjk6b" 
I0726 15:32:22.436805   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7g4tt" "namespace"="test-mhc-fjk6b" 
I0726 15:32:22.437643   10578 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-mf82f" "namespace"="test-mhc-fjk6b" 
I0726 15:32:22.450838   10578 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-mf82f-h5h7f" "namespace"="test-mhc-fjk6b" 
... skipping 7 lines ...
I0726 15:32:22.489084   10578 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-mf82f-h5h7f" "namespace"="test-mhc-fjk6b" 
I0726 15:32:22.489156   10578 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-mf82f-h5h7f" "namespace"="test-mhc-fjk6b" 
I0726 15:32:22.874264   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7g4tt" "namespace"="test-mhc-fjk6b" 
I0726 15:32:23.470997   10578 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-mf82f-h5h7f" "namespace"="test-mhc-fjk6b" 
I0726 15:32:23.471052   10578 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-mf82f-h5h7f" "namespace"="test-mhc-fjk6b" 
I0726 15:32:24.000673   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7g4tt" "namespace"="test-mhc-fjk6b" 
I0726 15:32:24.001049   10578 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-fjk6b/test-mhc-7g4tt/mhc-ms-mf82f-h5h7f/"
I0726 15:32:24.009050   10578 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-mf82f" "namespace"="test-mhc-fjk6b" 
I0726 15:32:24.013123   10578 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-mf82f-h5h7f" "namespace"="test-mhc-fjk6b" 
I0726 15:32:24.013203   10578 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-mf82f-h5h7f" "namespace"="test-mhc-fjk6b" 
I0726 15:32:24.020181   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7g4tt" "namespace"="test-mhc-fjk6b" 
I0726 15:32:24.020559   10578 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-fjk6b/test-mhc-7g4tt/mhc-ms-mf82f-h5h7f/"
I0726 15:32:24.022689   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7g4tt" "namespace"="test-mhc-fjk6b" 
I0726 15:32:24.023001   10578 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-fjk6b/test-mhc-7g4tt/mhc-ms-mf82f-h5h7f/"
I0726 15:32:24.023938   10578 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-mf82f" "namespace"="test-mhc-fjk6b" 
I0726 15:32:24.032663   10578 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-mf82f-h5h7f" "namespace"="test-mhc-fjk6b" 
I0726 15:32:24.032724   10578 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-mf82f-h5h7f" "namespace"="test-mhc-fjk6b" 
I0726 15:32:24.090658   10578 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-52kbf" "namespace"="test-mhc-fjk6b" "count"=1
I0726 15:32:24.090726   10578 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-52kbf" "namespace"="test-mhc-fjk6b" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-mf82f"
I0726 15:32:24.093226   10578 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-mf82f" "namespace"="test-mhc-fjk6b" "machine"="mhc-ms-mf82f-h5h7f"
I0726 15:32:24.098997   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7g4tt" "namespace"="test-mhc-fjk6b" 
I0726 15:32:24.099331   10578 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-52kbf" "namespace"="test-mhc-fjk6b" "descendants"="Machine sets: mhc-ms-mf82f;Worker machines: mhc-ms-mf82f-h5h7f" "indirect descendants count"=1
I0726 15:32:24.100183   10578 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-52kbf" "machine"="mhc-ms-mf82f-h5h7f" "namespace"="test-mhc-fjk6b" "cause"="cluster is being deleted" "node"=null
I0726 15:32:24.102549   10578 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-fjk6b/test-mhc-7g4tt/mhc-ms-mf82f-h5h7f/"
I0726 15:32:24.107344   10578 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-52kbf" "namespace"="test-mhc-fjk6b" "descendants"="Worker machines: mhc-ms-mf82f-h5h7f" "indirect descendants count"=1
I0726 15:32:24.109717   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-7g4tt" "namespace"="test-mhc-fjk6b" 
=== 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
I0726 15:32:24.194381   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hvpbq" "namespace"="test-mhc-hfsp2" 
inframachine created: test-mhc-machine-infra-xcjnh
... skipping 11 lines ...
I0726 15:32:24.319041   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hvpbq" "namespace"="test-mhc-hfsp2" 
I0726 15:32:24.321367   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hvpbq" "namespace"="test-mhc-hfsp2" 
I0726 15:32:24.322018   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hvpbq" "namespace"="test-mhc-hfsp2" 
I0726 15:32:24.323153   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hvpbq" "namespace"="test-mhc-hfsp2" 
I0726 15:32:24.324905   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hvpbq" "namespace"="test-mhc-hfsp2" 
I0726 15:32:24.326056   10578 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-52kbf" "machine"="mhc-ms-mf82f-h5h7f" "namespace"="test-mhc-fjk6b" "cause"="cluster is being deleted" "node"=null
E0726 15:32:24.338921   10578 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-gd6pl, got []"  "node"="test-mhc-node-gd6pl"
E0726 15:32:24.339174   10578 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-gd6pl, got []"  "node"="test-mhc-node-gd6pl"
E0726 15:32:24.339335   10578 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-gd6pl, got []"  "node"="test-mhc-node-gd6pl"
node created: test-mhc-node-gd6pl
E0726 15:32:24.365536   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-mf82f-h5h7f\" not found" "controller"="machine" "name"="mhc-ms-mf82f-h5h7f" "namespace"="test-mhc-fjk6b"
I0726 15:32:24.385559   10578 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-bj6qs" "target"="test-mhc-hfsp2/test-mhc-hvpbq/test-mhc-machine-bj6qs/"
I0726 15:32:24.398489   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hvpbq" "namespace"="test-mhc-hfsp2" 
I0726 15:32:24.422215   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hvpbq" "namespace"="test-mhc-hfsp2" 
I0726 15:32:24.432966   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hvpbq" "namespace"="test-mhc-hfsp2" 
I0726 15:32:24.440330   10578 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-bj6qs" "target"="test-mhc-hfsp2/test-mhc-hvpbq/test-mhc-machine-bj6qs/test-mhc-node-gd6pl"
I0726 15:32:24.458420   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hvpbq" "namespace"="test-mhc-hfsp2" 
Cleaning up nodes, machines and infra machines.
I0726 15:32:24.475874   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hvpbq" "namespace"="test-mhc-hfsp2" 
I0726 15:32:24.502190   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hvpbq" "namespace"="test-mhc-hfsp2" 
I0726 15:32:24.506105   10578 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-vhgs5" "namespace"="test-mhc-hfsp2" "descendants"="Worker machines: test-mhc-machine-bj6qs" "indirect descendants count"=1
I0726 15:32:24.518113   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hvpbq" "namespace"="test-mhc-hfsp2" 
=== RUN   TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted
I0726 15:32:24.523547   10578 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-vhgs5" "namespace"="test-mhc-hfsp2" "descendants"="Worker machines: test-mhc-machine-bj6qs" "indirect descendants count"=1
E0726 15:32:24.561389   10578 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-lls7z/test-cluster-7mlzh"
I0726 15:32:24.649025   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
inframachine created: test-mhc-machine-infra-h9mx4
machine created: test-mhc-machine-9vjgc
I0726 15:32:24.675329   10578 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0726 15:32:24.799509   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:24.800288   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
... skipping 298 lines ...
I0726 15:32:25.392191   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:25.393960   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:25.395614   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:25.398626   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:25.400547   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:25.404200   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
E0726 15:32:25.407789   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-bj6qs\" not found" "controller"="machine" "name"="test-mhc-machine-bj6qs" "namespace"="test-mhc-hfsp2"
I0726 15:32:25.408009   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:25.409870   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:25.412117   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:25.413919   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:25.415950   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:25.417868   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
... skipping 475 lines ...
I0726 15:32:26.398563   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:26.400403   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:26.402224   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:26.404037   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:26.405892   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:26.407712   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
E0726 15:32:26.408278   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4nlcb\" for machine \"test-mhc-machine-wjvf4\" in namespace \"test-mhc-lws89\": Cluster.cluster.x-k8s.io \"test-cluster-4nlcb\" not found" "controller"="machine" "name"="test-mhc-machine-wjvf4" "namespace"="test-mhc-lws89"
I0726 15:32:26.409578   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:26.411333   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:26.413126   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:26.415152   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:26.417065   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:26.419073   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
... skipping 516 lines ...
I0726 15:32:27.413842   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:27.415644   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:27.416994   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:27.417677   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:27.418731   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:27.420367   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
E0726 15:32:27.421594   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4nlcb\" for machine \"test-mhc-machine-zmv8v\" in namespace \"test-mhc-lws89\": Cluster.cluster.x-k8s.io \"test-cluster-4nlcb\" not found" "controller"="machine" "name"="test-mhc-machine-zmv8v" "namespace"="test-mhc-lws89"
I0726 15:32:27.421824   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:27.430199   10578 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-9vjgc" "target"="test-mhc-gvmdt/test-mhc-4wtjf/test-mhc-machine-9vjgc/"
I0726 15:32:27.450290   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
E0726 15:32:27.485667   10578 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-tnk79, got []"  "node"="test-mhc-node-tnk79"
E0726 15:32:27.485669   10578 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-tnk79, got []"  "node"="test-mhc-node-tnk79"
E0726 15:32:27.485671   10578 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-tnk79, got []"  "node"="test-mhc-node-tnk79"
node created: test-mhc-node-tnk79
I0726 15:32:27.492877   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:27.531769   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:27.539937   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:27.543348   10578 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-9vjgc" "target"="test-mhc-gvmdt/test-mhc-4wtjf/test-mhc-machine-9vjgc/test-mhc-node-tnk79"
I0726 15:32:27.560088   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:27.570722   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:27.588792   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
Cleaning up nodes, machines and infra machines.
I0726 15:32:27.596492   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:27.601203   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:27.605140   10578 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-9vjgc" "target"="test-mhc-gvmdt/test-mhc-4wtjf/test-mhc-machine-9vjgc/"
I0726 15:32:27.614209   10578 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-w24w7" "namespace"="test-mhc-gvmdt" "descendants"="Worker machines: test-mhc-machine-9vjgc" "indirect descendants count"=1
I0726 15:32:27.618495   10578 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-w24w7" "namespace"="test-mhc-gvmdt" "descendants"="Worker machines: test-mhc-machine-9vjgc" "indirect descendants count"=1
I0726 15:32:27.622105   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
I0726 15:32:27.624811   10578 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4wtjf" "namespace"="test-mhc-gvmdt" 
--- PASS: TestMachineHealthCheck_Reconcile (40.73s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist (0.07s)
... skipping 14 lines ...
    --- SKIP: TestMachineHealthCheck_Reconcile/when_a_machine_is_paused (0.00s)
        machinehealthcheck_controller_test.go:933: skipping until made stable
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created (0.41s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (3.11s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0726 15:32:27.632605   10578 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
E0726 15:32:27.634340   10578 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
E0726 15:32:27.635970   10578 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E0726 15:32:27.636236   10578 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
E0726 15:32:27.636769   10578 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
I0726 15:32:27.640379   10578 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0726 15:32:27.640989   10578 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0726 15:32:27.643335   10578 machinehealthcheck_controller.go:320]  "msg"="failed to patch healthy machine status for machine" "error"="machines.cluster.x-k8s.io \"machine1\" not found"  "machine"="machine1"
--- PASS: TestPatchTargets (0.01s)
=== RUN   TestGetTargetsFromMHC
=== RUN   TestGetTargetsFromMHC/with_no_matching_machines
=== RUN   TestGetTargetsFromMHC/when_a_machine's_node_is_missing
=== RUN   TestGetTargetsFromMHC/when_a_machine's_labels_do_not_match_the_selector
=== RUN   TestGetTargetsFromMHC/with_multiple_machines,_should_match_correct_nodes
... skipping 26 lines ...
--- PASS: TestMachineSetOwnerReference (0.00s)
    --- PASS: TestMachineSetOwnerReference/should_add_cluster_owner_reference_to_machine_set (0.00s)
    --- PASS: TestMachineSetOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_deployment (0.00s)
=== RUN   TestMachineSetReconcile
=== RUN   TestMachineSetReconcile/ignore_machine_sets_marked_for_deletion
=== RUN   TestMachineSetReconcile/records_event_if_reconcile_fails
E0726 15:32:27.653959   10578 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
E0726 15:32:27.655403   10578 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: 1627313488
Will run 16 of 16 specs

•E0726 15:32:27.789587   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-bfp6r\" not found" "controller"="cluster" "name"="test1-bfp6r" "namespace"="default"
I0726 15:32:28.422235   10578 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-w24w7" "machine"="test-mhc-machine-9vjgc" "namespace"="test-mhc-gvmdt" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-tnk79"}
E0726 15:32:28.459474   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-9vjgc\" not found" "controller"="machine" "name"="test-mhc-machine-9vjgc" "namespace"="test-mhc-gvmdt"
•I0726 15:32:28.904103   10578 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-jndtm" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0726 15:32:29.020698   10578 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-jndtm" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0726 15:32:29.025922   10578 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-jndtm" "namespace"="default"
E0726 15:32:30.044395   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jndtm: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jndtm" "namespace"="default"
•E0726 15:32:31.054988   10578 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-fjk6b/test-cluster-52kbf"
E0726 15:32:31.065682   10578 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-hfsp2/test-cluster-vhgs5"
E0726 15:32:31.080221   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-7cdns\" not found" "controller"="cluster" "name"="test3-7cdns" "namespace"="default"
E0726 15:32:32.081110   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jndtm: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jndtm" "namespace"="default"
E0726 15:32:33.092171   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jndtm: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jndtm" "namespace"="default"
•E0726 15:32:34.103990   10578 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-gvmdt/test-cluster-w24w7"
E0726 15:32:34.107689   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-zbwg2: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-zbwg2" "namespace"="default"
E0726 15:32:35.108447   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jndtm: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jndtm" "namespace"="default"
E0726 15:32:36.117472   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-zbwg2: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-zbwg2" "namespace"="default"
•E0726 15:32:36.648665   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4nlcb\" for machine \"test-mhc-machine-wjvf4\" in namespace \"test-mhc-lws89\": Cluster.cluster.x-k8s.io \"test-cluster-4nlcb\" not found" "controller"="machine" "name"="test-mhc-machine-wjvf4" "namespace"="test-mhc-lws89"
E0726 15:32:37.118387   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jndtm: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jndtm" "namespace"="default"
E0726 15:32:37.661969   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-4nlcb\" for machine \"test-mhc-machine-zmv8v\" in namespace \"test-mhc-lws89\": Cluster.cluster.x-k8s.io \"test-cluster-4nlcb\" not found" "controller"="machine" "name"="test-mhc-machine-zmv8v" "namespace"="test-mhc-lws89"
E0726 15:32:38.119159   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-zbwg2: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-zbwg2" "namespace"="default"
E0726 15:32:39.128646   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jndtm: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jndtm" "namespace"="default"
I0726 15:32:39.206913   10578 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-prr4x" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0726 15:32:39.215890   10578 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-prr4x" "namespace"="default" 
E0726 15:32:39.231877   10578 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-prr4x" "namespace"="default"
E0726 15:32:40.129456   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-zbwg2: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-zbwg2" "namespace"="default"
I0726 15:32:40.247123   10578 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-prr4x" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0726 15:32:40.247352   10578 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-prr4x" "namespace"="default" "noderef"="id-node-1"
E0726 15:32:40.261930   10578 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-prr4x" "namespace"="default"
E0726 15:32:41.134316   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jndtm: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jndtm" "namespace"="default"

------------------------------
• [SLOW TEST:5.036 seconds]
Cluster Reconciler
/home/prow/go/src/sigs.k8s.io/cluster-api/controllers/cluster_controller_test.go:45
  Should successfully set Status.ControlPlaneInitialized on the cluster object if controlplane is ready
... skipping 21 lines ...
I0726 15:32:41.212413   10578 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"
•I0726 15:32:41.213842   10578 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"
I0726 15:32:41.214464   10578 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"
I0726 15:32:41.215021   10578 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0726 15:32:41.215047   10578 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0726 15:32:41.215498   10578 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0726 15:32:41.216654   10578 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" 
•I0726 15:32:41.262407   10578 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-fg8g5" "machine"="test6-prr4x" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"601d8293-2a18-43b4-aa49-d0383b8a609e","apiVersion":"v1"}
E0726 15:32:41.280562   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-prr4x\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-prr4x" "namespace"="default"
I0726 15:32:41.281987   10578 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-qplzz" "namespace"="ms-test" "creating"=2 "need"=2
I0726 15:32:41.282030   10578 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-qplzz" "namespace"="ms-test" 
I0726 15:32:41.302961   10578 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-qplzz-9g282\"" "machineset"="ms-qplzz" "namespace"="ms-test" 
I0726 15:32:41.303032   10578 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-qplzz" "namespace"="ms-test" 
I0726 15:32:41.323853   10578 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-qplzz-ffnjt\"" "machineset"="ms-qplzz" "namespace"="ms-test" 
I0726 15:32:41.406304   10578 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-qplzz" "namespace"="ms-test" "creating"=1 "need"=2
I0726 15:32:41.406340   10578 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-qplzz" "namespace"="ms-test" 
I0726 15:32:41.419732   10578 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-qplzz-mk7gr\"" "machineset"="ms-qplzz" "namespace"="ms-test" 
E0726 15:32:41.651204   10578 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-qplzz-mk7gr-grm29 for machine ms-test/ms-qplzz-mk7gr: the cache is not started, can not read objects" "machineset"="ms-qplzz" "namespace"="ms-test" 
E0726 15:32:41.775514   10578 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="ms-test/test-cluster"
•I0726 15:32:41.824300   10578 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-t8ks7-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0726 15:32:41.824339   10578 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-t8ks7-6657c7fddb" "namespace"="md-test" 
I0726 15:32:41.838394   10578 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-t8ks7-6657c7fddb-q9wb9\"" "machineset"="md-t8ks7-6657c7fddb" "namespace"="md-test" 
I0726 15:32:41.838438   10578 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-t8ks7-6657c7fddb" "namespace"="md-test" 
I0726 15:32:41.848370   10578 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-t8ks7-6657c7fddb-rkdh2\"" "machineset"="md-t8ks7-6657c7fddb" "namespace"="md-test" 
I0726 15:32:41.957987   10578 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-t8ks7-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0726 15:32:41.958030   10578 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-t8ks7-6657c7fddb" "namespace"="md-test" 
I0726 15:32:41.967170   10578 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-t8ks7-6657c7fddb-2ltwz\"" "machineset"="md-t8ks7-6657c7fddb" "namespace"="md-test" 
I0726 15:32:41.967231   10578 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-t8ks7-6657c7fddb" "namespace"="md-test" 
I0726 15:32:41.976016   10578 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-t8ks7-6657c7fddb-b2gqx\"" "machineset"="md-t8ks7-6657c7fddb" "namespace"="md-test" 
I0726 15:32:42.030341   10578 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-t8ks7-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3
I0726 15:32:42.030400   10578 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-t8ks7-6657c7fddb" "namespace"="md-test" 
I0726 15:32:42.041868   10578 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-t8ks7-6657c7fddb-zs65c\"" "machineset"="md-t8ks7-6657c7fddb" "namespace"="md-test" 
E0726 15:32:42.134881   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-zbwg2: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-zbwg2" "namespace"="default"
I0726 15:32:42.136251   10578 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-t8ks7-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0726 15:32:42.136299   10578 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-t8ks7-cdfc6fd6c" "namespace"="md-test" 
I0726 15:32:42.149953   10578 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-t8ks7-cdfc6fd6c-ksq5h\"" "machineset"="md-t8ks7-cdfc6fd6c" "namespace"="md-test" 
E0726 15:32:42.273652   10578 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-t8ks7-cdfc6fd6c-ksq5h-qfqhp for machine md-test/md-t8ks7-cdfc6fd6c-ksq5h: the cache is not started, can not read objects" "machineset"="md-t8ks7-cdfc6fd6c" "namespace"="md-test" 
I0726 15:32:42.281067   10578 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-fg8g5" "machine"="test6-prr4x" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"601d8293-2a18-43b4-aa49-d0383b8a609e","apiVersion":"v1"}
E0726 15:32:42.281790   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-prr4x\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-prr4x" "namespace"="default"
I0726 15:32:42.302252   10578 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-t8ks7-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0726 15:32:42.302323   10578 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-t8ks7-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0726 15:32:42.305887   10578 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-t8ks7-6657c7fddb" "namespace"="md-test" "machine"="md-t8ks7-6657c7fddb-zs65c"
I0726 15:32:42.414670   10578 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-t8ks7-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0726 15:32:42.414724   10578 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-t8ks7-cdfc6fd6c" "namespace"="md-test" 
I0726 15:32:42.423664   10578 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-t8ks7-cdfc6fd6c-2kdt4\"" "machineset"="md-t8ks7-cdfc6fd6c" "namespace"="md-test" 
... skipping 11 lines ...
I0726 15:32:42.996533   10578 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-t8ks7-74d45c49c5-549tl\"" "machineset"="md-t8ks7-74d45c49c5" "namespace"="md-test" 
I0726 15:32:43.117091   10578 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-t8ks7-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2
I0726 15:32:43.117141   10578 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-t8ks7-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0726 15:32:43.120980   10578 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-t8ks7-cdfc6fd6c" "namespace"="md-test" "machine"="md-t8ks7-cdfc6fd6c-6m8k4"
I0726 15:32:43.135367   10578 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-fg8g5" "namespace"="default" "count"=1
I0726 15:32:43.135462   10578 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-fg8g5" "namespace"="default" "descendants"="Control plane machines: test6-prr4x" "indirect descendants count"=0
E0726 15:32:43.138992   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jndtm: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jndtm" "namespace"="default"
I0726 15:32:43.229618   10578 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-t8ks7-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=2
I0726 15:32:43.229672   10578 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-t8ks7-74d45c49c5" "namespace"="md-test" 
I0726 15:32:43.241034   10578 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-t8ks7-74d45c49c5-cnhns\"" "machineset"="md-t8ks7-74d45c49c5" "namespace"="md-test" 
E0726 15:32:43.282250   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"ms-qplzz-ffnjt\" in namespace \"ms-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="ms-qplzz-ffnjt" "namespace"="ms-test"
I0726 15:32:43.445958   10578 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-t8ks7-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1
I0726 15:32:43.445994   10578 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-t8ks7-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0726 15:32:43.449570   10578 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-t8ks7-cdfc6fd6c" "namespace"="md-test" "machine"="md-t8ks7-cdfc6fd6c-2kdt4"
I0726 15:32:43.464572   10578 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-t8ks7-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0726 15:32:43.464621   10578 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-t8ks7-74d45c49c5" "namespace"="md-test" 
I0726 15:32:43.473773   10578 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-t8ks7-74d45c49c5-qrlth\"" "machineset"="md-t8ks7-74d45c49c5" "namespace"="md-test" 
E0726 15:32:43.678856   10578 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="md-test/test-cluster"
•

Ran 16 of 16 Specs in 16.025 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (16.02s)
PASS
Tearing down test suite
E0726 15:32:43.681620   10578 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0726 15:32:43.681664   10578 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-702610843/tls.crt: no such file or directory"  
E0726 15:32:43.681677   10578 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
I0726 15:32:43.681679   10578 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
E0726 15:32:43.681690   10578 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-702610843/tls.crt: no such file or directory"  
I0726 15:32:43.681709   10578 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I0726 15:32:43.681725   10578 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0726 15:32:43.681740   10578 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
I0726 15:32:43.681764   10578 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0726 15:32:43.681808   10578 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0726 15:32:43.681680   10578 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
E0726 15:32:43.686312   10578 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error creating client and cache for remote cluster: error creating dynamic rest mapper for remote cluster \"md-test/test-cluster\": Get http://127.0.0.1:43837/api?timeout=10s: dial tcp 127.0.0.1:43837: connect: connection refused" "machineset"="md-t8ks7-74d45c49c5" "namespace"="md-test" 
E0726 15:32:43.687920   10578 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"md-test/test-cluster\": failed to retrieve kubeconfig secret for Cluster md-test/test-cluster: Get http://127.0.0.1:43837/api/v1/namespaces/md-test/secrets/test-cluster-kubeconfig: dial tcp 127.0.0.1:43837: connect: connection refused" "machineset"="md-t8ks7-74d45c49c5" "namespace"="md-test" 
E0726 15:32:43.688213   10578 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"md-test/test-cluster\": failed to retrieve kubeconfig secret for Cluster md-test/test-cluster: Get http://127.0.0.1:43837/api/v1/namespaces/md-test/secrets/test-cluster-kubeconfig: dial tcp 127.0.0.1:43837: connect: connection refused" "machineset"="md-t8ks7-74d45c49c5" "namespace"="md-test" 
E0726 15:32:43.689155   10578 machineset_controller.go:151] controllers/MachineSet "msg"="Failed to reconcile MachineSet" "error"="failed to patch MachineSet's Status: Patch http://127.0.0.1:43837/apis/cluster.x-k8s.io/v1alpha3/namespaces/md-test/machinesets/md-t8ks7-74d45c49c5/status: dial tcp 127.0.0.1:43837: connect: connection refused" "machineset"="md-t8ks7-74d45c49c5" "namespace"="md-test" 
E0726 15:32:43.689372   10578 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to patch MachineSet's Status: Patch http://127.0.0.1:43837/apis/cluster.x-k8s.io/v1alpha3/namespaces/md-test/machinesets/md-t8ks7-74d45c49c5/status: dial tcp 127.0.0.1:43837: connect: connection refused" "controller"="machineset" "name"="md-t8ks7-74d45c49c5" "namespace"="md-test"
E0726 15:32:43.689685   10578 event.go:272] Unable to write event: 'Post http://127.0.0.1:43837/api/v1/namespaces/md-test/events: dial tcp 127.0.0.1:43837: connect: connection refused' (may retry after sleeping)
E0726 15:32:43.724938   10578 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:43837/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1200&timeout=10s&timeoutSeconds=372&watch=true: dial tcp 127.0.0.1:43837: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	75.233s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 265 lines ...
•I0726 15:31:42.963589   10960 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0726 15:31:42.986852   10960 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":{}}}
I0726 15:31:43.187281   10960 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0726 15:31:43.187354   10960 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0726 15:31:43.187435   10960 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0726 15:31:43.716119   10960 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
E0726 15:31:45.742197   10960 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-tbs27/test-cluster"
•E0726 15:31:46.242204   10960 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-nmsxg/test-cluster"
•E0726 15:31:46.777969   10960 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:37905/?timeout=50ms: dial tcp 127.0.0.1:37905: connect: connection refused"  "cluster"="cluster-cache-test-8gj2c/test-cluster"
•E0726 15:31:46.986551   10960 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0726 15:31:46.986615   10960 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-763035933/tls.crt: no such file or directory"  
I0726 15:31:46.986712   10960 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0726 15:31:47.061734   10960 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:40965/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=146&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:40965: connect: connection refused


Ran 5 of 5 Specs in 16.908 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (16.91s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	17.076s
?   	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
I0726 15:31:55.067511   11629 controller.go:133]  "msg"="Cluster Controller has not yet set OwnerRef" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcileNoClusterOwnerRef (0.00s)
=== RUN   TestReconcileNoKCP
--- PASS: TestReconcileNoKCP (0.00s)
=== RUN   TestReconcileNoCluster
E0726 15:31:55.068815   11629 controller.go:129]  "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
I0726 15:31:55.069470   11629 controller.go:139]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I0726 15:31:55.069645   11629 controller.go:139]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcilePaused (0.00s)
=== RUN   TestReconcileClusterNoEndpoints
--- FAIL: TestReconcileClusterNoEndpoints (0.00s)
    controller_test.go:427: 
        Unexpected error:
            <*errors.withStack | 0xc0001cad20>: {
                error: {
                    cause: {
                        error: {
                            cause: {
                                ErrStatus: {
                                    TypeMeta: {Kind: "", APIVersion: ""},
                                    ListMeta: {
                                        SelfLink: "",
                                        ResourceVersion: "",
... skipping 11 lines ...
                                        Causes: nil,
                                        RetryAfterSeconds: 0,
                                    },
                                    Code: 404,
                                },
                            },
                            msg: "failed to retrieve kubeconfig secret for Cluster test/foo",
                        },
                        stack: [0x1464401, 0x1734009, 0x172d97f, 0x174564c, 0x50fb29, 0x461751],
                    },
                    msg: "failed to create metadata only client",
                },
                stack: [0x172dc2b, 0x174564c, 0x50fb29, 0x461751],
            }
            failed to create metadata only client: failed to retrieve kubeconfig secret for Cluster test/foo: secrets "foo-kubeconfig" not found
        occurred
=== RUN   TestKubeadmControlPlaneReconciler_adoption
=== RUN   TestKubeadmControlPlaneReconciler_adoption/adopts_existing_Machines
I0726 15:31:55.080853   11629 controller.go:263]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-pps4q9" "kubeadmControlPlane"="kcp-foo-pps4q9" "namespace"="test" 
=== RUN   TestKubeadmControlPlaneReconciler_adoption/adopts_v1alpha2_cluster_secrets
I0726 15:31:58.287284   11629 controller.go:263]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-qxeg5k" "kubeadmControlPlane"="kcp-foo-qxeg5k" "namespace"="test" 
... skipping 4 lines ...
--- PASS: TestKubeadmControlPlaneReconciler_adoption (11.29s)
    --- PASS: TestKubeadmControlPlaneReconciler_adoption/adopts_existing_Machines (3.21s)
    --- PASS: TestKubeadmControlPlaneReconciler_adoption/adopts_v1alpha2_cluster_secrets (2.27s)
    --- PASS: TestKubeadmControlPlaneReconciler_adoption/Deleted_KubeadmControlPlanes_don't_adopt_machines (2.96s)
    --- PASS: TestKubeadmControlPlaneReconciler_adoption/refuses_to_adopt_Machines_that_are_more_than_one_version_old (2.85s)
=== RUN   TestReconcileInitializeControlPlane
--- FAIL: TestReconcileInitializeControlPlane (0.00s)
    controller_test.go:897: 
        Unexpected error:
            <*errors.withStack | 0xc000b58000>: {
                error: {
                    cause: {
                        error: {
                            cause: {
                                ErrStatus: {
                                    TypeMeta: {Kind: "", APIVersion: ""},
                                    ListMeta: {
                                        SelfLink: "",
                                        ResourceVersion: "",
... skipping 11 lines ...
                                        Causes: nil,
                                        RetryAfterSeconds: 0,
                                    },
                                    Code: 404,
                                },
                            },
                            msg: "failed to retrieve kubeconfig secret for Cluster test/foo",
                        },
                        stack: [0x1464401, 0x1734009, 0x172d97f, 0x174838b, 0x50fb29, 0x461751],
                    },
                    msg: "failed to create metadata only client",
                },
                stack: [0x172dc2b, 0x174838b, 0x50fb29, 0x461751],
            }
            failed to create metadata only client: failed to retrieve kubeconfig secret for Cluster test/foo: secrets "foo-kubeconfig" not found
        occurred
=== RUN   TestKubeadmControlPlaneReconciler_updateCoreDNS
=== RUN   TestKubeadmControlPlaneReconciler_updateCoreDNS/updates_configmaps_and_deployments_successfully
=== RUN   TestKubeadmControlPlaneReconciler_updateCoreDNS/returns_no_error_when_no_ClusterConfiguration_is_specified
=== RUN   TestKubeadmControlPlaneReconciler_updateCoreDNS/should_not_return_an_error_when_there_is_no_CoreDNS_configmap
=== RUN   TestKubeadmControlPlaneReconciler_updateCoreDNS/should_not_return_an_error_when_there_is_no_CoreDNS_deployment
... skipping 178 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
I0726 15:32:11.181446   11629 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
I0726 15:32:11.181544   11629 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: 1627313500
Will run 1 of 1 specs

E0726 15:32:11.219406   11629 controller.go:129]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="Cluster.cluster.x-k8s.io \"kcp-foo-001auw\" not found" "kubeadmControlPlane"="kcp-foo-001auw" "namespace"="test" 
•

Ran 1 of 1 Specs in 0.035 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (0.04s)
=== RUN   TestKubeadmControlPlaneReconciler_upgradeControlPlane
I0726 15:32:11.221066   11629 controller.go:263]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-054au7" "kubeadmControlPlane"="kcp-foo-054au7" "namespace"="test" 
I0726 15:32:13.365659   11629 controller.go:348]  "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-054au7" "kubeadmControlPlane"="kcp-foo-054au7" "namespace"="test" "needRollout"=["kcp-foo-054au7-h5z26"]
I0726 15:32:13.365889   11629 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-054au7" "kubeadmControlPlane"="kcp-foo-054au7" "namespace"="test" "failures"="[machine kcp-foo-054au7-nd7rp does not have APIServerPodHealthy condition, machine kcp-foo-054au7-nd7rp does not have ControllerManagerPodHealthy condition, machine kcp-foo-054au7-nd7rp does not have SchedulerPodHealthy condition, machine kcp-foo-054au7-nd7rp does not have EtcdPodHealthy condition, machine kcp-foo-054au7-nd7rp does not have EtcdMemberHealthy condition]"
--- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (2.15s)
FAIL
I0726 15:32:13.367023   11629 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
FAIL	sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers	32.687s
I0726 15:31:52.192917   11596 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"
I0726 15:31:52.193042   11596 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster"
I0726 15:31:52.193073   11596 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"
I0726 15:31:52.193088   11596 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster"
I0726 15:31:52.193183   11596 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"
I0726 15:31:52.193199   11596 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-machine"
... skipping 51 lines ...
==================================
Random Seed: 1627313499
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: 1627313499
Will run 7 of 7 specs

•••••••
Ran 7 of 7 Specs in 0.000 seconds
SUCCESS! -- 7 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestMachineCollection (0.00s)
=== RUN   TestUpdateEtcdConditions
=== RUN   TestUpdateEtcdConditions/if_list_nodes_return_an_error_should_report_all_the_conditions_Unknown
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_be_ignored_if_there_are_provisioning_machines
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_report_a_problem_at_KCP_level_if_there_are_no_provisioning_machines
=== RUN   TestUpdateEtcdConditions/failure_creating_the_etcd_client_should_report_unknown_condition
... skipping 297 lines ...
    --- PASS: TestUpdateKubeProxyImageInfo/returns_error_if_image_repository_is_invalid (0.00s)
    --- PASS: TestUpdateKubeProxyImageInfo/does_not_update_image_repository_when_no_kube-proxy_update_is_requested (0.00s)
=== RUN   TestRemoveMachineFromKubeadmConfigMap
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_find_kubeadm-config_for_Kubernetes_version_<_1.22.0
E0726 15:31:54.874948   11596 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0726 15:32:03.198064   11596 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0726 15:32:12.184157   11596 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0726 15:32:23.314474   11596 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0726 15:32:39.787767   11596 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0726 15:32:52.796378   11596 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0726 15:33:10.443871   11596 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0726 15:33:31.367272   11596 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0726 15:34:02.383859   11596 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0726 15:34:47.541249   11596 workload_cluster.go:325]  "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 72 lines ...
=== RUN   TestClusterStatus/returns_cluster_status_with_kubeadm_config
--- PASS: TestClusterStatus (0.00s)
    --- PASS: TestClusterStatus/returns_cluster_status (0.00s)
    --- PASS: TestClusterStatus/returns_cluster_status_with_kubeadm_config (0.00s)
PASS
I0726 15:34:47.551593   11596 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0726 15:34:47.551744   11596 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0726 15:34:47.551795   11596 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-493419548/tls.crt: no such file or directory"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/internal	188.015s
=== RUN   TestEtcdMembers_WithErrors
--- PASS: TestEtcdMembers_WithErrors (0.00s)
=== RUN   TestEtcdMembers_WithSuccess
--- PASS: TestEtcdMembers_WithSuccess (0.00s)
PASS
... skipping 287 lines ...
I0726 15:32:01.627246   11926 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0726 15:32:01.632052   11926 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"ConfigMap","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0726 15:32:01.732520   11926 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0726 15:32:01.832976   11926 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0726 15:32:01.833047   11926 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0726 15:32:01.911759   11926 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-am2e2y"} 
E0726 15:32:01.938495   11926 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"
•I0726 15:32:02.988615   11926 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-vlrube"} 
E0726 15:32:03.042291   11926 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"
•E0726 15:32:04.097126   11926 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"
•E0726 15:32:05.120515   11926 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"
E0726 15:32:06.290444   11926 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"
•E0726 15:32:07.316621   11926 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"
E0726 15:32:08.340628   11926 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"
•E0726 15:32:08.342631   11926 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0726 15:32:08.342706   11926 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-985220693/tls.crt: no such file or directory"  
E0726 15:32:08.342751   11926 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0726 15:32:08.342783   11926 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-985220693/tls.crt: no such file or directory"  
I0726 15:32:08.343286   11926 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 
I0726 15:32:08.343377   11926 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
I0726 15:32:08.343713   11926 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 5 of 5 Specs in 19.173 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (19.17s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/addons/controllers	19.259s
?   	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
E0726 15:31:54.592296   12118 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.02s)
    --- PASS: TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready (0.01s)
    --- 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.01s)
=== RUN   TestMachinePoolFinalizer
... skipping 96 lines ...
I0726 15:32:06.300958   12118 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0726 15:32:06.324859   12118 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••I0726 15:32:06.327190   12118 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


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


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