This job view page is being replaced by Spyglass soon. Check out the new job view.
PRsbueringer: 🐛 cherry-pick: update CoreDNS ClusterRole (Kubernetes>=1.22,CoreDNS >= 1.8.1)
ResultFAILURE
Tests 0 failed / 0 succeeded
Started2021-07-16 17:41
Elapsed2m25s
Revisione4077eabf1c3ca55f0034dd3f35ad6ee7f2bdc61
Refs 4957

No Test Failures!


Error lines from build-log.txt

... skipping 777 lines ...
I0716 17:42:49.022362    8637 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0716 17:42:49.023058    8637 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0716 17:42:49.024203    8637 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0716 17:42:49.024550    8637 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0716 17:42:49.024716    8637 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=43665
I0716 17:42:49.804979    8637 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" 
•E0716 17:42:49.815389    8637 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
I0716 17:42:49.815408    8637 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0716 17:42:49.815440    8637 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-236421987/tls.crt: no such file or directory"  
E0716 17:42:49.815475    8637 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0716 17:42:49.815494    8637 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-236421987/tls.crt: no such file or directory"  


Ran 1 of 1 Specs in 10.825 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (10.83s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	35.407s
=== 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 1398 lines ...
I0716 17:42:39.928186   10470 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
I0716 17:42:39.928228   10470 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}}}
I0716 17:42:39.928295   10470 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machine" "worker count"=1
I0716 17:42:39.928338   10470 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0716 17:42:39.928382   10470 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0716 17:42:39.928486   10470 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machineset" "worker count"=1
2021/07/16 17:42:40 http: TLS handshake error from 127.0.0.1:57044: 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
I0716 17:42:40.434382   10470 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"
I0716 17:42:40.437177   10470 cluster_controller_phases.go:76]  "msg"="Could not find external object for cluster, requeuing" "cluster"="test-cluster" "namespace"="test-namespace" "refGroupVersionKind"={"Group":"infrastructure.cluster.x-k8s.io","Version":"v1alpha3","Kind":"InfrastructureMachine"} "refName"="test"
... skipping 105 lines ...
    --- PASS: TestReconcileBootstrap/existing_machine,_machineset_owner_and_version_v1alpha2,_and_ownerref_updated (0.00s)
=== RUN   TestReconcileInfrastructure
=== RUN   TestReconcileInfrastructure/new_machine,_infrastructure_config_ready
I0716 17:42:40.485908   10470 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
I0716 17:42:40.487416   10470 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"
E0716 17:42:40.487727   10470 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
I0716 17:42:40.488057   10470 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
I0716 17:42:40.857885   10470 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0716 17:42:40.958525   10470 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0716 17:42:40.972471   10470 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-ntktb" "namespace"="test-machine-watches-498t5" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0716 17:42:40.972621   10470 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0716 17:42:41.082849   10470 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-ntktb" "namespace"="test-machine-watches-498t5" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0716 17:42:41.082942   10470 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0716 17:42:41.183423   10470 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-ntktb" "namespace"="test-machine-watches-498t5" "noderef"="node-1"
E0716 17:42:41.207092   10470 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0716 17:42:41.207143   10470 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0716 17:42:41.258496   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"machine-created-ntktb\" in namespace \"test-machine-watches-498t5\": cannot find node with matching ProviderID" "controller"="machine" "name"="machine-created-ntktb" "namespace"="test-machine-watches-498t5"
E0716 17:42:42.263680   10470 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-ntktb\" in namespace \"test-machine-watches-498t5\", requeuing: requeue in 1s"  
E0716 17:42:42.272529   10470 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-ntktb\" in namespace \"test-machine-watches-498t5\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-ntktb\" in namespace \"test-machine-watches-498t5\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-ntktb" "namespace"="test-machine-watches-498t5"
--- PASS: TestWatches (1.81s)
=== 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
I0716 17:42:42.384264   10470 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-m5gzk" "namespace"="test-machine-watches-498t5" "count"=1
I0716 17:42:42.384349   10470 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-m5gzk" "namespace"="test-machine-watches-498t5" "descendants"="Worker machines: machine-created-ntktb" "indirect descendants count"=0
I0716 17:42:42.397661   10470 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-m5gzk" "namespace"="test-machine-watches-498t5" "count"=1
I0716 17:42:42.397715   10470 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-m5gzk" "namespace"="test-machine-watches-498t5" "descendants"="Worker machines: machine-created-ntktb" "indirect descendants count"=0
I0716 17:42:43.273111   10470 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-m5gzk" "machine"="machine-created-ntktb" "namespace"="test-machine-watches-498t5" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"c245e954-ed6e-4034-84bc-4adac4604f15","apiVersion":"v1"}
E0716 17:42:43.325359   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-ntktb\" not found" "controller"="machine" "name"="machine-created-ntktb" "namespace"="test-machine-watches-498t5"
E0716 17:42:44.363989   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-vb9k2\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-sndz8\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-sndz8: secrets \"machine-reconcile-sndz8-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-vb9k2" "namespace"="default"
I0716 17:42:45.364580   10470 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-sndz8" "machine"="machine-created-vb9k2" "namespace"="default" "cause"="noderef is nil" "node"=null
I0716 17:42:45.402623   10470 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-sndz8" "machine"="machine-created-vb9k2" "namespace"="default" "cause"="noderef is nil" "node"=null
I0716 17:42:45.421113   10470 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-sndz8" "machine"="machine-created-vb9k2" "namespace"="default" "cause"="noderef is nil" "node"=null
E0716 17:42:45.463537   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-vb9k2\" not found" "controller"="machine" "name"="machine-created-vb9k2" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.17s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.17s)
=== RUN   TestMachineFinalizer
=== RUN   TestMachineFinalizer/should_add_a_machine_finalizer_to_the_machine_if_it_doesn't_have_one
=== RUN   TestMachineFinalizer/should_append_the_machine_finalizer_to_the_machine_if_it_already_has_a_finalizer
--- PASS: TestMachineFinalizer (0.00s)
... skipping 3 lines ...
=== RUN   TestMachineOwnerReference/should_add_owner_reference_to_machine_referencing_a_cluster_with_correct_type_meta
I0716 17:42:45.474479   10470 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine2" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0716 17:42:45.474566   10470 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine2" "namespace"="default" 
=== RUN   TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set
I0716 17:42:45.477163   10470 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine3" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0716 17:42:45.477240   10470 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine3" "namespace"="default" 
E0716 17:42:45.484860   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-sndz8\" not found" "controller"="cluster" "name"="machine-reconcile-sndz8" "namespace"="default"
=== RUN   TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner
I0716 17:42:45.514507   10470 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine4" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0716 17:42:45.514737   10470 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine4" "namespace"="default" 
--- PASS: TestMachineOwnerReference (0.04s)
    --- PASS: TestMachineOwnerReference/should_add_owner_reference_to_machine_referencing_a_cluster_with_correct_type_meta (0.00s)
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set (0.01s)
... skipping 122 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
I0716 17:42:45.656148   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pbp2n" "namespace"="test-mhc-8bf6c" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
I0716 17:42:45.717746   10470 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0716 17:42:45.717916   10470 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-g4fcm\" not found"  "cluster"="test-mhc-8bf6c/test-cluster-g4fcm"
E0716 17:42:45.724513   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-pbp2n\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-pbp2n\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-pbp2n" "namespace"="test-mhc-8bf6c"
=== 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
I0716 17:42:46.727684   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pbp2n" "namespace"="test-mhc-8bf6c" 
I0716 17:42:46.727812   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pzspn" "namespace"="test-mhc-h7gdx" 
I0716 17:42:46.727853   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-v278t" "namespace"="test-mhc-9nlxt" 
I0716 17:42:46.727890   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-96vcc" "namespace"="test-mhc-qqshp" 
I0716 17:42:46.744127   10470 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0716 17:42:46.763575   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-96vcc" "namespace"="test-mhc-qqshp" 
I0716 17:42:46.812709   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-96vcc" "namespace"="test-mhc-qqshp" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
E0716 17:42:46.847745   10470 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-qqshp/test-cluster-qvdf6"
I0716 17:42:46.852555   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-86pd7" "namespace"="test-mhc-ltwtk" 
E0716 17:42:46.855154   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-qvdf6\" not found" "controller"="cluster" "name"="test-cluster-qvdf6" "namespace"="test-mhc-qqshp"
I0716 17:42:46.893654   10470 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0716 17:42:47.020028   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-86pd7" "namespace"="test-mhc-ltwtk" 
E0716 17:42:47.058485   10470 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-ltwtk/test-cluster-n9nf8"
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0716 17:42:47.062877   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-86pd7" "namespace"="test-mhc-ltwtk" 
I0716 17:42:47.183560   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wrm6w" "namespace"="test-mhc-snlsv" 
inframachine created: test-mhc-machine-infra-m2gw2
I0716 17:42:47.214831   10470 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-87c9n
I0716 17:42:47.238376   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wrm6w" "namespace"="test-mhc-snlsv" 
I0716 17:42:47.244102   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wrm6w" "namespace"="test-mhc-snlsv" 
I0716 17:42:47.244474   10470 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-snlsv/test-mhc-wrm6w/test-mhc-machine-87c9n/"
I0716 17:42:47.273804   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wrm6w" "namespace"="test-mhc-snlsv" 
I0716 17:42:47.274138   10470 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-snlsv/test-mhc-wrm6w/test-mhc-machine-87c9n/"
E0716 17:42:47.331685   10470 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-hl8vp"
E0716 17:42:47.331691   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-hl8vp, got []"  "node"="test-mhc-node-hl8vp"
node created: test-mhc-node-hl8vp
I0716 17:42:47.342028   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wrm6w" "namespace"="test-mhc-snlsv" 
inframachine created: test-mhc-machine-infra-t8sl2
machine created: test-mhc-machine-jzkh2
I0716 17:42:47.366555   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wrm6w" "namespace"="test-mhc-snlsv" 
I0716 17:42:47.372293   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wrm6w" "namespace"="test-mhc-snlsv" 
... skipping 20 lines ...
I0716 17:42:47.419751   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wrm6w" "namespace"="test-mhc-snlsv" 
I0716 17:42:47.421297   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wrm6w" "namespace"="test-mhc-snlsv" 
I0716 17:42:47.422585   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wrm6w" "namespace"="test-mhc-snlsv" 
I0716 17:42:47.424536   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wrm6w" "namespace"="test-mhc-snlsv" 
I0716 17:42:47.426310   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wrm6w" "namespace"="test-mhc-snlsv" 
I0716 17:42:47.428075   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wrm6w" "namespace"="test-mhc-snlsv" 
I0716 17:42:47.428584   10470 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-snlsv/test-mhc-wrm6w/test-mhc-machine-jzkh2/"
I0716 17:42:47.440825   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wrm6w" "namespace"="test-mhc-snlsv" 
I0716 17:42:47.453076   10470 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-snlsv/test-mhc-wrm6w/test-mhc-machine-jzkh2/"
I0716 17:42:47.455122   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wrm6w" "namespace"="test-mhc-snlsv" 
I0716 17:42:47.455674   10470 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-snlsv/test-mhc-wrm6w/test-mhc-machine-jzkh2/"
I0716 17:42:47.459339   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wrm6w" "namespace"="test-mhc-snlsv" 
I0716 17:42:47.459704   10470 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-snlsv/test-mhc-wrm6w/test-mhc-machine-jzkh2/"
node created: test-mhc-node-sbd4l
E0716 17:42:47.471611   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-sbd4l, got []"  "node"="test-mhc-node-sbd4l"
E0716 17:42:47.471820   10470 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-sbd4l"
I0716 17:42:47.477571   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wrm6w" "namespace"="test-mhc-snlsv" 
I0716 17:42:47.481058   10470 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-jzkh2" "namespace"="test-mhc-snlsv" "noderef"="test-mhc-node-sbd4l"
I0716 17:42:47.493663   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wrm6w" "namespace"="test-mhc-snlsv" 
I0716 17:42:47.495391   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wrm6w" "namespace"="test-mhc-snlsv" 
Cleaning up nodes, machines and infra machines.
I0716 17:42:47.501763   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wrm6w" "namespace"="test-mhc-snlsv" 
I0716 17:42:47.510280   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wrm6w" "namespace"="test-mhc-snlsv" 
I0716 17:42:47.512705   10470 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-snlsv/test-mhc-wrm6w/test-mhc-machine-87c9n/"
I0716 17:42:47.533923   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wrm6w" "namespace"="test-mhc-snlsv" 
I0716 17:42:47.534084   10470 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-8fqqv" "machine"="test-mhc-machine-87c9n" "namespace"="test-mhc-snlsv" "cause"="no control plane members" "node"={"name":"test-mhc-node-hl8vp"}
I0716 17:42:47.534348   10470 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-snlsv/test-mhc-wrm6w/test-mhc-machine-87c9n/"
I0716 17:42:47.534748   10470 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-snlsv/test-mhc-wrm6w/test-mhc-machine-jzkh2/"
E0716 17:42:47.568428   10470 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-snlsv/test-cluster-8fqqv"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
E0716 17:42:47.596206   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-87c9n\" not found" "controller"="machine" "name"="test-mhc-machine-87c9n" "namespace"="test-mhc-snlsv"
inframachine created: test-mhc-machine-infra-xdzcm
machine created: test-mhc-machine-cqg72
E0716 17:42:47.738282   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-wrm6w\" not found" "controller"="machinehealthcheck" "name"="test-mhc-wrm6w" "namespace"="test-mhc-snlsv"
E0716 17:42:47.867692   10470 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-498t5/machine-reconcile-m5gzk"
E0716 17:42:48.596681   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-8fqqv\" for machine \"test-mhc-machine-jzkh2\" in namespace \"test-mhc-snlsv\": Cluster.cluster.x-k8s.io \"test-cluster-8fqqv\" not found" "controller"="machine" "name"="test-mhc-machine-jzkh2" "namespace"="test-mhc-snlsv"
I0716 17:42:48.738631   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:48.759362   10470 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0716 17:42:48.893165   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wrm6w" "namespace"="test-mhc-snlsv" 
I0716 17:42:48.893390   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:48.898332   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:48.902502   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
... skipping 330 lines ...
I0716 17:42:49.612322   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:49.613559   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:49.614171   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:49.615538   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:49.617139   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:49.618835   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:49.619096   10470 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-plm92/test-mhc-lfq2n/test-mhc-machine-cqg72/"
E0716 17:42:49.619129   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-8fqqv\" for machine \"test-mhc-machine-jzkh2\" in namespace \"test-mhc-snlsv\": Cluster.cluster.x-k8s.io \"test-cluster-8fqqv\" not found" "controller"="machine" "name"="test-mhc-machine-jzkh2" "namespace"="test-mhc-snlsv"
I0716 17:42:49.627748   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:49.628014   10470 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-plm92/test-mhc-lfq2n/test-mhc-machine-cqg72/"
node created: test-mhc-node-hmkbb
E0716 17:42:49.634253   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-hmkbb, got []"  "node"="test-mhc-node-hmkbb"
I0716 17:42:49.648898   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
inframachine created: test-mhc-machine-infra-bmrgw
machine created: test-mhc-machine-t6jr4
I0716 17:42:49.669259   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:49.675094   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:49.676104   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
... skipping 379 lines ...
I0716 17:42:50.659829   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:50.662916   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:50.666300   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:50.667556   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:50.670674   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:50.673403   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
E0716 17:42:50.673578   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-8fqqv\" for machine \"test-mhc-machine-jzkh2\" in namespace \"test-mhc-snlsv\": Cluster.cluster.x-k8s.io \"test-cluster-8fqqv\" not found" "controller"="machine" "name"="test-mhc-machine-jzkh2" "namespace"="test-mhc-snlsv"
I0716 17:42:50.674879   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:50.676153   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:50.677370   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:50.678837   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:50.680959   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:50.681965   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
... skipping 370 lines ...
I0716 17:42:51.694702   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:51.697043   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:51.699420   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:51.702584   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:51.710663   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:51.713194   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:51.713554   10470 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-plm92/test-mhc-lfq2n/test-mhc-machine-t6jr4/"
I0716 17:42:51.729084   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:51.729512   10470 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-plm92/test-mhc-lfq2n/test-mhc-machine-t6jr4/"
I0716 17:42:51.733543   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
E0716 17:42:51.733614   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-8fqqv\" for machine \"test-mhc-machine-jzkh2\" in namespace \"test-mhc-snlsv\": Cluster.cluster.x-k8s.io \"test-cluster-8fqqv\" not found" "controller"="machine" "name"="test-mhc-machine-jzkh2" "namespace"="test-mhc-snlsv"
I0716 17:42:51.733979   10470 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-plm92/test-mhc-lfq2n/test-mhc-machine-t6jr4/"
E0716 17:42:51.785483   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-sppzz, got []"  "node"="test-mhc-node-sppzz"
node created: test-mhc-node-sppzz
I0716 17:42:51.792783   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
inframachine created: test-mhc-machine-infra-ndggw
I0716 17:42:51.809168   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
machine created: test-mhc-machine-l9gz5
I0716 17:42:51.812073   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
... skipping 313 lines ...
I0716 17:42:52.768058   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:52.770130   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:52.772444   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:52.773900   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:52.775380   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:52.776564   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
E0716 17:42:52.776568   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-8fqqv\" for machine \"test-mhc-machine-jzkh2\" in namespace \"test-mhc-snlsv\": Cluster.cluster.x-k8s.io \"test-cluster-8fqqv\" not found" "controller"="machine" "name"="test-mhc-machine-jzkh2" "namespace"="test-mhc-snlsv"
I0716 17:42:52.777770   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:52.779207   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:52.780781   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:52.782063   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:52.783361   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:52.784627   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
... skipping 306 lines ...
I0716 17:42:53.778067   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:53.780348   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:53.782939   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:53.784529   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:53.786000   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:53.788596   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:53.788952   10470 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-plm92/test-mhc-lfq2n/test-mhc-machine-l9gz5/"
E0716 17:42:53.798069   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-8fqqv\" for machine \"test-mhc-machine-jzkh2\" in namespace \"test-mhc-snlsv\": Cluster.cluster.x-k8s.io \"test-cluster-8fqqv\" not found" "controller"="machine" "name"="test-mhc-machine-jzkh2" "namespace"="test-mhc-snlsv"
I0716 17:42:53.803421   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:53.804011   10470 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-plm92/test-mhc-lfq2n/test-mhc-machine-l9gz5/"
E0716 17:42:53.841963   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-bch4j, got []"  "node"="test-mhc-node-bch4j"
node created: test-mhc-node-bch4j
I0716 17:42:53.848092   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:53.848650   10470 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-plm92/test-mhc-lfq2n/test-mhc-machine-l9gz5/test-mhc-node-bch4j"
Cleaning up nodes, machines and infra machines.
Cleaning up nodes, machines and infra machines.
I0716 17:42:53.868033   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:53.876413   10470 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-plm92/test-mhc-lfq2n/test-mhc-machine-l9gz5/"
I0716 17:42:53.891363   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:53.891901   10470 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-plm92/test-mhc-lfq2n/test-mhc-machine-cqg72/"
I0716 17:42:53.909486   10470 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-plm92/test-mhc-lfq2n/test-mhc-machine-t6jr4/"
I0716 17:42:53.909720   10470 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-7t7xn" "namespace"="test-mhc-plm92" "count"=2
I0716 17:42:53.909771   10470 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-7t7xn" "namespace"="test-mhc-plm92" "descendants"="Worker machines: test-mhc-machine-l9gz5,test-mhc-machine-cqg72,test-mhc-machine-t6jr4" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
I0716 17:42:53.925851   10470 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-7t7xn" "namespace"="test-mhc-plm92" "count"=2
I0716 17:42:53.925897   10470 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-7t7xn" "namespace"="test-mhc-plm92" "descendants"="Worker machines: test-mhc-machine-cqg72,test-mhc-machine-t6jr4,test-mhc-machine-l9gz5" "indirect descendants count"=1
I0716 17:42:53.932039   10470 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-plm92/test-mhc-lfq2n/test-mhc-machine-l9gz5/"
E0716 17:42:53.935911   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-lfq2n\" not found" "controller"="machinehealthcheck" "name"="test-mhc-lfq2n" "namespace"="test-mhc-plm92"
inframachine created: test-mhc-machine-infra-z2m6x
machine created: test-mhc-machine-kb6v2
I0716 17:42:54.798643   10470 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-7t7xn" "machine"="test-mhc-machine-l9gz5" "namespace"="test-mhc-plm92" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-bch4j"}
E0716 17:42:54.848234   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-l9gz5\" not found" "controller"="machine" "name"="test-mhc-machine-l9gz5" "namespace"="test-mhc-plm92"
I0716 17:42:54.936345   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lfq2n" "namespace"="test-mhc-plm92" 
I0716 17:42:54.936482   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
I0716 17:42:54.955110   10470 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0716 17:42:55.087404   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
I0716 17:42:55.092842   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
I0716 17:42:55.103010   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
I0716 17:42:55.146961   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
I0716 17:42:55.228109   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
I0716 17:42:55.389136   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
I0716 17:42:55.710380   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
I0716 17:42:55.848843   10470 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-7t7xn" "machine"="test-mhc-machine-t6jr4" "namespace"="test-mhc-plm92" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-sppzz"}
E0716 17:42:55.901832   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-t6jr4\" not found" "controller"="machine" "name"="test-mhc-machine-t6jr4" "namespace"="test-mhc-plm92"
I0716 17:42:56.351330   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
I0716 17:42:56.902481   10470 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-7t7xn" "machine"="test-mhc-machine-cqg72" "namespace"="test-mhc-plm92" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-hmkbb"}
E0716 17:42:56.985366   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-cqg72\" not found" "controller"="machine" "name"="test-mhc-machine-cqg72" "namespace"="test-mhc-plm92"
I0716 17:42:57.632504   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
E0716 17:42:57.985793   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-8fqqv\" for machine \"test-mhc-machine-jzkh2\" in namespace \"test-mhc-snlsv\": Cluster.cluster.x-k8s.io \"test-cluster-8fqqv\" not found" "controller"="machine" "name"="test-mhc-machine-jzkh2" "namespace"="test-mhc-snlsv"
E0716 17:42:58.939762   10470 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-plm92/test-cluster-7t7xn"
I0716 17:42:58.995209   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
I0716 17:42:59.001847   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
E0716 17:42:59.002522   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-8fqqv\" for machine \"test-mhc-machine-jzkh2\" in namespace \"test-mhc-snlsv\": Cluster.cluster.x-k8s.io \"test-cluster-8fqqv\" not found" "controller"="machine" "name"="test-mhc-machine-jzkh2" "namespace"="test-mhc-snlsv"
I0716 17:42:59.035558   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
node created: test-mhc-node-l2cb8
E0716 17:42:59.093636   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-l2cb8, got []"  "node"="test-mhc-node-l2cb8"
I0716 17:42:59.104786   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
inframachine created: test-mhc-machine-infra-7mfb4
machine created: test-mhc-machine-fkdgs
I0716 17:42:59.137183   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
I0716 17:42:59.267778   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
I0716 17:42:59.272975   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
... skipping 6 lines ...
I0716 17:43:00.022855   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
I0716 17:43:00.038830   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
I0716 17:43:00.042688   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
I0716 17:43:00.043853   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
I0716 17:43:00.049249   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
I0716 17:43:00.055269   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
E0716 17:43:00.057219   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-8fqqv\" for machine \"test-mhc-machine-jzkh2\" in namespace \"test-mhc-snlsv\": Cluster.cluster.x-k8s.io \"test-cluster-8fqqv\" not found" "controller"="machine" "name"="test-mhc-machine-jzkh2" "namespace"="test-mhc-snlsv"
I0716 17:43:00.080917   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
E0716 17:43:00.134472   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-fjbn2, got []"  "node"="test-mhc-node-fjbn2"
node created: test-mhc-node-fjbn2
I0716 17:43:00.149662   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
inframachine created: test-mhc-machine-infra-rtt7j
I0716 17:43:00.163148   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
I0716 17:43:00.164852   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
machine created: test-mhc-machine-tnfks
... skipping 5 lines ...
I0716 17:43:01.126289   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
I0716 17:43:01.133852   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
I0716 17:43:01.142002   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
I0716 17:43:01.147381   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
I0716 17:43:01.178128   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
I0716 17:43:01.179581   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
E0716 17:43:01.181386   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-fcswj, got []"  "node"="test-mhc-node-fcswj"
node created: test-mhc-node-fcswj
Cleaning up nodes, machines and infra machines.
I0716 17:43:01.188865   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
I0716 17:43:01.202640   10470 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-tnfks" "namespace"="test-mhc-zhclq" "noderef"="test-mhc-node-fcswj"
I0716 17:43:01.211814   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
I0716 17:43:01.234897   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
I0716 17:43:01.236252   10470 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-k9nmf" "machine"="test-mhc-machine-fkdgs" "namespace"="test-mhc-zhclq" "cause"="no control plane members" "node"={"name":"test-mhc-node-fjbn2"}
Cleaning up nodes, machines and infra machines.
E0716 17:43:01.317080   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-fkdgs\" not found" "controller"="machine" "name"="test-mhc-machine-fkdgs" "namespace"="test-mhc-zhclq"
I0716 17:43:01.320901   10470 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-k9nmf" "namespace"="test-mhc-zhclq" "count"=2
I0716 17:43:01.320989   10470 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-k9nmf" "namespace"="test-mhc-zhclq" "descendants"="Worker machines: test-mhc-machine-tnfks,test-mhc-machine-kb6v2" "indirect descendants count"=0
I0716 17:43:01.326838   10470 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-k9nmf" "namespace"="test-mhc-zhclq" "count"=2
I0716 17:43:01.326891   10470 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-k9nmf" "namespace"="test-mhc-zhclq" "descendants"="Worker machines: test-mhc-machine-kb6v2,test-mhc-machine-tnfks" "indirect descendants count"=0
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_less_than_the_NodeStartupTimeout
inframachine created: test-mhc-machine-infra-rh4cl
machine created: test-mhc-machine-t2bl7
I0716 17:43:01.432872   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x6l25" "namespace"="test-mhc-l55jw" 
I0716 17:43:01.444661   10470 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0716 17:43:01.466131   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bk64q" "namespace"="test-mhc-zhclq" 
I0716 17:43:01.466220   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x6l25" "namespace"="test-mhc-l55jw" 
I0716 17:43:02.318954   10470 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-k9nmf" "machine"="test-mhc-machine-tnfks" "namespace"="test-mhc-zhclq" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"test-mhc-node-fcswj","uid":"de13b2f0-e7fc-4a7e-a927-1659e64dd27f","apiVersion":"v1"}
E0716 17:43:02.364412   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-tnfks\" not found" "controller"="machine" "name"="test-mhc-machine-tnfks" "namespace"="test-mhc-zhclq"
I0716 17:43:03.372062   10470 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-k9nmf" "machine"="test-mhc-machine-kb6v2" "namespace"="test-mhc-zhclq" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-l2cb8"}
E0716 17:43:03.448219   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-kb6v2\" not found" "controller"="machine" "name"="test-mhc-machine-kb6v2" "namespace"="test-mhc-zhclq"
E0716 17:43:04.451359   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-8fqqv\" for machine \"test-mhc-machine-jzkh2\" in namespace \"test-mhc-snlsv\": Cluster.cluster.x-k8s.io \"test-cluster-8fqqv\" not found" "controller"="machine" "name"="test-mhc-machine-jzkh2" "namespace"="test-mhc-snlsv"
I0716 17:43:05.462395   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x6l25" "namespace"="test-mhc-l55jw" 
I0716 17:43:05.471819   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x6l25" "namespace"="test-mhc-l55jw" 
I0716 17:43:05.489654   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x6l25" "namespace"="test-mhc-l55jw" 
I0716 17:43:05.505415   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x6l25" "namespace"="test-mhc-l55jw" 
E0716 17:43:05.514146   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-mss22, got []"  "node"="test-mhc-node-mss22"
node created: test-mhc-node-mss22
E0716 17:43:05.514829   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-mss22, got []"  "node"="test-mhc-node-mss22"
I0716 17:43:05.518094   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x6l25" "namespace"="test-mhc-l55jw" 
I0716 17:43:05.529411   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x6l25" "namespace"="test-mhc-l55jw" 
inframachine created: test-mhc-machine-infra-wjd9d
I0716 17:43:05.541507   10470 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-t2bl7" "namespace"="test-mhc-l55jw" "noderef"="test-mhc-node-mss22"
machine created: test-mhc-machine-75mdp
I0716 17:43:05.556317   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x6l25" "namespace"="test-mhc-l55jw" 
... skipping 2 lines ...
I0716 17:43:05.578546   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x6l25" "namespace"="test-mhc-l55jw" 
I0716 17:43:05.601450   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x6l25" "namespace"="test-mhc-l55jw" 
I0716 17:43:05.613684   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x6l25" "namespace"="test-mhc-l55jw" 
I0716 17:43:05.620135   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x6l25" "namespace"="test-mhc-l55jw" 
I0716 17:43:05.650012   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x6l25" "namespace"="test-mhc-l55jw" 
node created: test-mhc-node-5998h
E0716 17:43:05.658615   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-5998h, got []"  "node"="test-mhc-node-5998h"
E0716 17:43:05.658827   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-5998h, got []"  "node"="test-mhc-node-5998h"
I0716 17:43:05.662556   10470 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-75mdp" "namespace"="test-mhc-l55jw" "noderef"="test-mhc-node-5998h"
E0716 17:43:05.667354   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-5998h, got []"  "node"="test-mhc-node-5998h"
E0716 17:43:05.667406   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-5998h, got []"  "node"="test-mhc-node-5998h"
E0716 17:43:05.667407   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-5998h, got []"  "node"="test-mhc-node-5998h"
E0716 17:43:05.667495   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-5998h, got []"  "node"="test-mhc-node-5998h"
I0716 17:43:05.671915   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x6l25" "namespace"="test-mhc-l55jw" 
inframachine created: test-mhc-machine-infra-vtdhq
machine created: test-mhc-machine-mwtp4
I0716 17:43:05.701381   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x6l25" "namespace"="test-mhc-l55jw" 
I0716 17:43:05.713513   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x6l25" "namespace"="test-mhc-l55jw" 
I0716 17:43:05.715005   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x6l25" "namespace"="test-mhc-l55jw" 
... skipping 5 lines ...
I0716 17:43:05.842204   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x6l25" "namespace"="test-mhc-l55jw" 
I0716 17:43:05.848397   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x6l25" "namespace"="test-mhc-l55jw" 
I0716 17:43:05.860649   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x6l25" "namespace"="test-mhc-l55jw" 
Cleaning up nodes, machines and infra machines.
I0716 17:43:05.892236   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x6l25" "namespace"="test-mhc-l55jw" 
Cleaning up nodes, machines and infra machines.
E0716 17:43:05.897665   10470 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 \"test-mhc-machine-infra-vtdhq\" for Machine \"test-mhc-machine-mwtp4\" in namespace \"test-mhc-l55jw\", requeuing: requeue in 1s"  
I0716 17:43:05.902677   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x6l25" "namespace"="test-mhc-l55jw" 
I0716 17:43:05.903213   10470 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="FailureReason: 0xc000f7d710" "reason"="MachineHasFailure" "target"="test-mhc-l55jw/test-mhc-x6l25/test-mhc-machine-mwtp4/"
E0716 17:43:05.904525   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine \"test-mhc-machine-infra-vtdhq\" for Machine \"test-mhc-machine-mwtp4\" in namespace \"test-mhc-l55jw\", requeuing: requeue in 1s" "controller"="machine" "name"="test-mhc-machine-mwtp4" "namespace"="test-mhc-l55jw"
I0716 17:43:05.918395   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x6l25" "namespace"="test-mhc-l55jw" 
I0716 17:43:05.919842   10470 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-l55jw/test-mhc-x6l25/test-mhc-machine-t2bl7/"
I0716 17:43:05.968281   10470 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-xcxwx" "namespace"="test-mhc-l55jw" "count"=3
I0716 17:43:05.968363   10470 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-xcxwx" "namespace"="test-mhc-l55jw" "descendants"="Worker machines: test-mhc-machine-t2bl7,test-mhc-machine-75mdp,test-mhc-machine-mwtp4" "indirect descendants count"=0
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_longer_than_the_NodeStartupTimeout
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine's_Node_has_gone_away
=== RUN   TestMachineHealthCheck_Reconcile/should_react_when_a_Node_transitions_to_unhealthy
I0716 17:43:05.975929   10470 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-xcxwx" "namespace"="test-mhc-l55jw" "count"=3
I0716 17:43:05.975983   10470 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-xcxwx" "namespace"="test-mhc-l55jw" "descendants"="Worker machines: test-mhc-machine-t2bl7,test-mhc-machine-75mdp,test-mhc-machine-mwtp4" "indirect descendants count"=0
inframachine created: test-mhc-machine-infra-mdvxk
machine created: test-mhc-machine-lcz5k
I0716 17:43:06.127044   10470 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="FailureReason: 0xc001082ae0" "reason"="MachineHasFailure" "target"="test-mhc-l55jw/test-mhc-x6l25/test-mhc-machine-mwtp4/"
E0716 17:43:06.143684   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-x6l25\" not found" "controller"="machinehealthcheck" "name"="test-mhc-x6l25" "namespace"="test-mhc-l55jw"
E0716 17:43:06.343429   10470 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-zhclq/test-cluster-k9nmf"
I0716 17:43:06.905084   10470 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-xcxwx" "machine"="test-mhc-machine-mwtp4" "namespace"="test-mhc-l55jw" "cause"="cluster is being deleted" "node"=null
E0716 17:43:06.963304   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-mwtp4\" not found" "controller"="machine" "name"="test-mhc-machine-mwtp4" "namespace"="test-mhc-l55jw"
I0716 17:43:07.144021   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:07.160484   10470 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0716 17:43:07.282550   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x6l25" "namespace"="test-mhc-l55jw" 
I0716 17:43:07.282645   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:07.283602   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:07.286329   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
... skipping 324 lines ...
I0716 17:43:08.025431   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:08.027534   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:08.029598   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:08.031553   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:08.033630   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:08.035284   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
E0716 17:43:08.036578   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-t2bl7\" not found" "controller"="machine" "name"="test-mhc-machine-t2bl7" "namespace"="test-mhc-l55jw"
I0716 17:43:08.037240   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:08.039075   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:08.041161   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:08.042776   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:08.044296   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:08.045867   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
... skipping 524 lines ...
I0716 17:43:09.077277   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:09.078923   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:09.080540   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:09.082205   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:09.084001   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:09.085538   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
E0716 17:43:09.087277   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-75mdp\" not found" "controller"="machine" "name"="test-mhc-machine-75mdp" "namespace"="test-mhc-l55jw"
I0716 17:43:09.087410   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:09.089065   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:09.090609   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:09.092176   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:09.093717   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:09.095212   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
... skipping 478 lines ...
I0716 17:43:10.100690   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:10.101170   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:10.102252   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:10.103883   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:10.105698   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:10.106901   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:10.107062   10470 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-hp8qs/test-mhc-ntjbc/test-mhc-machine-lcz5k/"
E0716 17:43:10.108017   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-8fqqv\" for machine \"test-mhc-machine-jzkh2\" in namespace \"test-mhc-snlsv\": Cluster.cluster.x-k8s.io \"test-cluster-8fqqv\" not found" "controller"="machine" "name"="test-mhc-machine-jzkh2" "namespace"="test-mhc-snlsv"
I0716 17:43:10.117983   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:10.118277   10470 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-hp8qs/test-mhc-ntjbc/test-mhc-machine-lcz5k/"
E0716 17:43:10.144332   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-4xzkr, got []"  "node"="test-mhc-node-4xzkr"
E0716 17:43:10.144541   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-4xzkr, got []"  "node"="test-mhc-node-4xzkr"
node created: test-mhc-node-4xzkr
I0716 17:43:10.154176   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:10.196368   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:10.206043   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:10.207187   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:10.207399   10470 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-hp8qs/test-mhc-ntjbc/test-mhc-machine-lcz5k/test-mhc-node-4xzkr"
I0716 17:43:10.236034   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:10.236451   10470 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-hp8qs/test-mhc-ntjbc/test-mhc-machine-lcz5k/test-mhc-node-4xzkr"
Cleaning up nodes, machines and infra machines.
I0716 17:43:10.244665   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:10.244961   10470 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-hp8qs/test-mhc-ntjbc/test-mhc-machine-lcz5k/"
I0716 17:43:10.283988   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:10.284260   10470 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-hp8qs/test-mhc-ntjbc/test-mhc-machine-lcz5k/"
I0716 17:43:10.285555   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:10.285845   10470 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-hp8qs/test-mhc-ntjbc/test-mhc-machine-lcz5k/"
I0716 17:43:10.295993   10470 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-q6n5h" "namespace"="test-mhc-hp8qs" "descendants"="Worker machines: test-mhc-machine-lcz5k" "indirect descendants count"=1
I0716 17:43:10.300330   10470 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-q6n5h" "namespace"="test-mhc-hp8qs" "descendants"="Worker machines: test-mhc-machine-lcz5k" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0716 17:43:10.302424   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntjbc" "namespace"="test-mhc-hp8qs" 
I0716 17:43:10.395603   10470 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-pnrnm" "namespace"="test-mhc-plfmc" "creating"=1 "need"=1
I0716 17:43:10.395647   10470 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-pnrnm" "namespace"="test-mhc-plfmc" 
I0716 17:43:10.419626   10470 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-pnrnm-l9bsv\"" "machineset"="mhc-ms-pnrnm" "namespace"="test-mhc-plfmc" 
I0716 17:43:10.481403   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-crr7m" "namespace"="test-mhc-plfmc" 
I0716 17:43:10.501762   10470 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0716 17:43:10.641839   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-crr7m" "namespace"="test-mhc-plfmc" 
I0716 17:43:10.648323   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-crr7m" "namespace"="test-mhc-plfmc" 
E0716 17:43:10.992134   10470 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-l55jw/test-cluster-xcxwx"
I0716 17:43:11.108673   10470 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-q6n5h" "machine"="test-mhc-machine-lcz5k" "namespace"="test-mhc-hp8qs" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-4xzkr"}
E0716 17:43:11.154083   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-lcz5k\" not found" "controller"="machine" "name"="test-mhc-machine-lcz5k" "namespace"="test-mhc-hp8qs"
I0716 17:43:11.642079   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-crr7m" "namespace"="test-mhc-plfmc" 
I0716 17:43:12.176181   10470 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-pnrnm" "namespace"="test-mhc-plfmc" 
I0716 17:43:12.176547   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-crr7m" "namespace"="test-mhc-plfmc" 
I0716 17:43:12.179242   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-crr7m" "namespace"="test-mhc-plfmc" 
I0716 17:43:12.191899   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-crr7m" "namespace"="test-mhc-plfmc" 
I0716 17:43:12.193501   10470 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-pnrnm" "namespace"="test-mhc-plfmc" 
... skipping 6 lines ...
I0716 17:43:12.257599   10470 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-pnrnm-l9bsv" "namespace"="test-mhc-plfmc" 
I0716 17:43:12.257662   10470 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-pnrnm-l9bsv" "namespace"="test-mhc-plfmc" 
I0716 17:43:12.644324   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-crr7m" "namespace"="test-mhc-plfmc" 
I0716 17:43:13.250808   10470 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-pnrnm-l9bsv" "namespace"="test-mhc-plfmc" 
I0716 17:43:13.250860   10470 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-pnrnm-l9bsv" "namespace"="test-mhc-plfmc" 
I0716 17:43:14.000943   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-crr7m" "namespace"="test-mhc-plfmc" 
I0716 17:43:14.001431   10470 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-plfmc/test-mhc-crr7m/mhc-ms-pnrnm-l9bsv/"
I0716 17:43:14.009244   10470 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-pnrnm" "namespace"="test-mhc-plfmc" 
I0716 17:43:14.014319   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-crr7m" "namespace"="test-mhc-plfmc" 
I0716 17:43:14.014558   10470 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-plfmc/test-mhc-crr7m/mhc-ms-pnrnm-l9bsv/"
I0716 17:43:14.016427   10470 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-pnrnm-l9bsv" "namespace"="test-mhc-plfmc" 
I0716 17:43:14.016475   10470 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-pnrnm-l9bsv" "namespace"="test-mhc-plfmc" 
I0716 17:43:14.026060   10470 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-cd4b2" "namespace"="test-mhc-plfmc" "count"=1
I0716 17:43:14.026119   10470 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-cd4b2" "namespace"="test-mhc-plfmc" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-pnrnm"
I0716 17:43:14.028230   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-crr7m" "namespace"="test-mhc-plfmc" 
I0716 17:43:14.028632   10470 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-plfmc/test-mhc-crr7m/mhc-ms-pnrnm-l9bsv/"
I0716 17:43:14.029778   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-crr7m" "namespace"="test-mhc-plfmc" 
I0716 17:43:14.030035   10470 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-plfmc/test-mhc-crr7m/mhc-ms-pnrnm-l9bsv/"
I0716 17:43:14.032404   10470 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-pnrnm" "namespace"="test-mhc-plfmc" "machine"="mhc-ms-pnrnm-l9bsv"
I0716 17:43:14.035650   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-crr7m" "namespace"="test-mhc-plfmc" 
I0716 17:43:14.041386   10470 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-pnrnm-l9bsv" "namespace"="test-mhc-plfmc" 
I0716 17:43:14.041445   10470 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-pnrnm-l9bsv" "namespace"="test-mhc-plfmc" 
I0716 17:43:14.042141   10470 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-cd4b2" "machine"="mhc-ms-pnrnm-l9bsv" "namespace"="test-mhc-plfmc" "cause"="cluster is being deleted" "node"=null
I0716 17:43:14.043545   10470 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-cd4b2" "namespace"="test-mhc-plfmc" "descendants"="Machine sets: mhc-ms-pnrnm;Worker machines: mhc-ms-pnrnm-l9bsv" "indirect descendants count"=1
... skipping 4 lines ...
I0716 17:43:14.321931   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
inframachine created: test-mhc-machine-infra-ccrxk
I0716 17:43:14.341445   10470 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-j74f8
I0716 17:43:14.380929   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
I0716 17:43:14.390191   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
E0716 17:43:14.391751   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-pnrnm-l9bsv\" not found" "controller"="machine" "name"="mhc-ms-pnrnm-l9bsv" "namespace"="test-mhc-plfmc"
I0716 17:43:14.397165   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
I0716 17:43:14.399646   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
I0716 17:43:14.402833   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
I0716 17:43:14.404049   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
I0716 17:43:14.406339   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
I0716 17:43:14.407396   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
... skipping 463 lines ...
I0716 17:43:15.300958   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
I0716 17:43:15.303366   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
I0716 17:43:15.305566   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
I0716 17:43:15.307690   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
I0716 17:43:15.311174   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
I0716 17:43:15.313284   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
E0716 17:43:15.315079   10470 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-hp8qs/test-cluster-q6n5h"
I0716 17:43:15.315192   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
I0716 17:43:15.317430   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
I0716 17:43:15.319147   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
I0716 17:43:15.320896   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
I0716 17:43:15.322816   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
I0716 17:43:15.324604   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
... skipping 33 lines ...
I0716 17:43:15.397045   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
I0716 17:43:15.398747   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
I0716 17:43:15.400286   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
I0716 17:43:15.400863   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
I0716 17:43:15.401994   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
I0716 17:43:15.403566   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
E0716 17:43:15.403895   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-8fqqv\" for machine \"test-mhc-machine-jzkh2\" in namespace \"test-mhc-snlsv\": Cluster.cluster.x-k8s.io \"test-cluster-8fqqv\" not found" "controller"="machine" "name"="test-mhc-machine-jzkh2" "namespace"="test-mhc-snlsv"
I0716 17:43:15.404445   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
I0716 17:43:15.435031   10470 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-j74f8" "target"="test-mhc-vgllg/test-mhc-ljlzm/test-mhc-machine-j74f8/"
I0716 17:43:15.447820   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
E0716 17:43:15.475888   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-wvmh8, got []"  "node"="test-mhc-node-wvmh8"
E0716 17:43:15.476372   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-wvmh8, got []"  "node"="test-mhc-node-wvmh8"
node created: test-mhc-node-wvmh8
I0716 17:43:15.484550   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
I0716 17:43:15.508671   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
I0716 17:43:15.519852   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
I0716 17:43:15.524014   10470 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-j74f8" "target"="test-mhc-vgllg/test-mhc-ljlzm/test-mhc-machine-j74f8/test-mhc-node-wvmh8"
I0716 17:43:15.543315   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
Cleaning up nodes, machines and infra machines.
I0716 17:43:15.558620   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
I0716 17:43:15.561562   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
I0716 17:43:15.563786   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljlzm" "namespace"="test-mhc-vgllg" 
I0716 17:43:15.573938   10470 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-dt8wf" "namespace"="test-mhc-vgllg" "descendants"="Worker machines: test-mhc-machine-j74f8" "indirect descendants count"=1
... skipping 307 lines ...
I0716 17:43:16.437173   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2pp5w" "namespace"="test-mhc-mksbr" 
I0716 17:43:16.439148   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2pp5w" "namespace"="test-mhc-mksbr" 
I0716 17:43:16.440944   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2pp5w" "namespace"="test-mhc-mksbr" 
I0716 17:43:16.443030   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2pp5w" "namespace"="test-mhc-mksbr" 
I0716 17:43:16.445542   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2pp5w" "namespace"="test-mhc-mksbr" 
I0716 17:43:16.447989   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2pp5w" "namespace"="test-mhc-mksbr" 
E0716 17:43:16.448145   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-j74f8\" not found" "controller"="machine" "name"="test-mhc-machine-j74f8" "namespace"="test-mhc-vgllg"
I0716 17:43:16.450528   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2pp5w" "namespace"="test-mhc-mksbr" 
I0716 17:43:16.452126   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2pp5w" "namespace"="test-mhc-mksbr" 
I0716 17:43:16.453833   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2pp5w" "namespace"="test-mhc-mksbr" 
I0716 17:43:16.455430   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2pp5w" "namespace"="test-mhc-mksbr" 
I0716 17:43:16.457311   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2pp5w" "namespace"="test-mhc-mksbr" 
I0716 17:43:16.459197   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2pp5w" "namespace"="test-mhc-mksbr" 
... skipping 499 lines ...
I0716 17:43:17.454369   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2pp5w" "namespace"="test-mhc-mksbr" 
I0716 17:43:17.456102   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2pp5w" "namespace"="test-mhc-mksbr" 
I0716 17:43:17.456932   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2pp5w" "namespace"="test-mhc-mksbr" 
I0716 17:43:17.458038   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2pp5w" "namespace"="test-mhc-mksbr" 
I0716 17:43:17.459687   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2pp5w" "namespace"="test-mhc-mksbr" 
I0716 17:43:17.460901   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2pp5w" "namespace"="test-mhc-mksbr" 
I0716 17:43:17.464854   10470 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-rmzck" "target"="test-mhc-mksbr/test-mhc-2pp5w/test-mhc-machine-rmzck/"
I0716 17:43:17.482443   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2pp5w" "namespace"="test-mhc-mksbr" 
E0716 17:43:17.541157   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-n2cf9, got []"  "node"="test-mhc-node-n2cf9"
E0716 17:43:17.541360   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-n2cf9, got []"  "node"="test-mhc-node-n2cf9"
node created: test-mhc-node-n2cf9
E0716 17:43:17.541585   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-n2cf9, got []"  "node"="test-mhc-node-n2cf9"
I0716 17:43:17.554013   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2pp5w" "namespace"="test-mhc-mksbr" 
I0716 17:43:17.589452   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2pp5w" "namespace"="test-mhc-mksbr" 
I0716 17:43:17.600298   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2pp5w" "namespace"="test-mhc-mksbr" 
I0716 17:43:17.604465   10470 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-rmzck" "target"="test-mhc-mksbr/test-mhc-2pp5w/test-mhc-machine-rmzck/test-mhc-node-n2cf9"
I0716 17:43:17.623431   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2pp5w" "namespace"="test-mhc-mksbr" 
I0716 17:43:17.635652   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2pp5w" "namespace"="test-mhc-mksbr" 
I0716 17:43:17.671203   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2pp5w" "namespace"="test-mhc-mksbr" 
I0716 17:43:17.676094   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2pp5w" "namespace"="test-mhc-mksbr" 
Cleaning up nodes, machines and infra machines.
I0716 17:43:17.681506   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2pp5w" "namespace"="test-mhc-mksbr" 
I0716 17:43:17.688459   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2pp5w" "namespace"="test-mhc-mksbr" 
I0716 17:43:17.692951   10470 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-rmzck" "target"="test-mhc-mksbr/test-mhc-2pp5w/test-mhc-machine-rmzck/"
I0716 17:43:17.704432   10470 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-xsrq2" "namespace"="test-mhc-mksbr" "count"=1
I0716 17:43:17.704516   10470 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-xsrq2" "namespace"="test-mhc-mksbr" "descendants"="Worker machines: test-mhc-machine-rmzck" "indirect descendants count"=0
I0716 17:43:17.708731   10470 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-xsrq2" "namespace"="test-mhc-mksbr" "count"=1
I0716 17:43:17.708808   10470 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-xsrq2" "namespace"="test-mhc-mksbr" "descendants"="Worker machines: test-mhc-machine-rmzck" "indirect descendants count"=0
I0716 17:43:17.712130   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2pp5w" "namespace"="test-mhc-mksbr" 
I0716 17:43:17.714260   10470 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2pp5w" "namespace"="test-mhc-mksbr" 
... skipping 16 lines ...
    --- SKIP: TestMachineHealthCheck_Reconcile/when_a_machine_is_paused (0.00s)
        machinehealthcheck_controller_test.go:933: skipping until made stable
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created (1.54s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (2.13s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0716 17:43:17.717170   10470 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
E0716 17:43:17.719278   10470 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
E0716 17:43:17.723954   10470 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E0716 17:43:17.724298   10470 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
E0716 17:43:17.724963   10470 machinehealthcheck_controller.go:480]  "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node node1, got [machine1 machine2]"  "node"="node1"
=== RUN   TestNodeToMachineHealthCheck/when_no_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_two_MachineHealthChecks_exist_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node,_but_not_in_the_Machine's_cluster
--- PASS: TestNodeToMachineHealthCheck (0.01s)
    --- PASS: TestNodeToMachineHealthCheck/when_the_object_passed_isn't_a_Node (0.00s)
... skipping 31 lines ...
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_nil (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_not_an_int_or_percentage (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_an_int (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_a_40%_(of_5) (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_a_60%_(of_7) (0.00s)
=== RUN   TestPatchTargets
I0716 17:43:17.729414   10470 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0716 17:43:17.729939   10470 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0716 17:43:17.731522   10470 machinehealthcheck_controller.go:320]  "msg"="failed to patch healthy machine status for machine" "error"="machines.cluster.x-k8s.io \"machine1\" not found"  "machine"="machine1"
--- PASS: TestPatchTargets (0.00s)
=== RUN   TestGetTargetsFromMHC
=== RUN   TestGetTargetsFromMHC/with_no_matching_machines
=== RUN   TestGetTargetsFromMHC/when_a_machine's_node_is_missing
=== RUN   TestGetTargetsFromMHC/when_a_machine's_labels_do_not_match_the_selector
=== RUN   TestGetTargetsFromMHC/with_multiple_machines,_should_match_correct_nodes
... skipping 26 lines ...
--- PASS: TestMachineSetOwnerReference (0.00s)
    --- PASS: TestMachineSetOwnerReference/should_add_cluster_owner_reference_to_machine_set (0.00s)
    --- PASS: TestMachineSetOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_deployment (0.00s)
=== RUN   TestMachineSetReconcile
=== RUN   TestMachineSetReconcile/ignore_machine_sets_marked_for_deletion
=== RUN   TestMachineSetReconcile/records_event_if_reconcile_fails
E0716 17:43:17.740049   10470 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
E0716 17:43:17.741644   10470 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 62 lines ...

I0716 17:43:17.804208   10470 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-tvddq-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0716 17:43:17.804278   10470 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-tvddq-6657c7fddb" "namespace"="md-test" 
I0716 17:43:17.818716   10470 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-tvddq-6657c7fddb-9llxh\"" "machineset"="md-tvddq-6657c7fddb" "namespace"="md-test" 
I0716 17:43:17.818805   10470 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-tvddq-6657c7fddb" "namespace"="md-test" 
I0716 17:43:17.839321   10470 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-tvddq-6657c7fddb-cp6gx\"" "machineset"="md-tvddq-6657c7fddb" "namespace"="md-test" 
E0716 17:43:17.847817   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"test-mhc-machine-rmzck\" in namespace \"test-mhc-mksbr\": cannot find node with matching ProviderID" "controller"="machine" "name"="test-mhc-machine-rmzck" "namespace"="test-mhc-mksbr"
I0716 17:43:17.952226   10470 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-tvddq-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0716 17:43:17.952289   10470 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-tvddq-6657c7fddb" "namespace"="md-test" 
I0716 17:43:17.963631   10470 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-tvddq-6657c7fddb-mhvcl\"" "machineset"="md-tvddq-6657c7fddb" "namespace"="md-test" 
I0716 17:43:17.963715   10470 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-tvddq-6657c7fddb" "namespace"="md-test" 
I0716 17:43:17.978466   10470 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-tvddq-6657c7fddb-flwkf\"" "machineset"="md-tvddq-6657c7fddb" "namespace"="md-test" 
I0716 17:43:18.008356   10470 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-tvddq-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3
I0716 17:43:18.008468   10470 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-tvddq-6657c7fddb" "namespace"="md-test" 
I0716 17:43:18.020578   10470 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-tvddq-6657c7fddb-lgdrm\"" "machineset"="md-tvddq-6657c7fddb" "namespace"="md-test" 
I0716 17:43:18.122058   10470 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-tvddq-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0716 17:43:18.122119   10470 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-tvddq-cdfc6fd6c" "namespace"="md-test" 
I0716 17:43:18.134616   10470 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-tvddq-cdfc6fd6c-cbx22\"" "machineset"="md-tvddq-cdfc6fd6c" "namespace"="md-test" 
E0716 17:43:18.215292   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-cdfc6fd6c-cbx22-r2jmv, got []"  "node"="md-tvddq-cdfc6fd6c-cbx22-r2jmv"
E0716 17:43:18.215446   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-cdfc6fd6c-cbx22-r2jmv, got []"  "node"="md-tvddq-cdfc6fd6c-cbx22-r2jmv"
E0716 17:43:18.215672   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-cdfc6fd6c-cbx22-r2jmv, got []"  "node"="md-tvddq-cdfc6fd6c-cbx22-r2jmv"
E0716 17:43:18.319705   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-cdfc6fd6c-cbx22-r2jmv, got []"  "node"="md-tvddq-cdfc6fd6c-cbx22-r2jmv"
E0716 17:43:18.319766   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-cdfc6fd6c-cbx22-r2jmv, got []"  "node"="md-tvddq-cdfc6fd6c-cbx22-r2jmv"
E0716 17:43:18.319765   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-cdfc6fd6c-cbx22-r2jmv, got []"  "node"="md-tvddq-cdfc6fd6c-cbx22-r2jmv"
E0716 17:43:18.319882   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-cdfc6fd6c-cbx22-r2jmv, got []"  "node"="md-tvddq-cdfc6fd6c-cbx22-r2jmv"
E0716 17:43:18.320279   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-cdfc6fd6c-cbx22-r2jmv, got []"  "node"="md-tvddq-cdfc6fd6c-cbx22-r2jmv"
E0716 17:43:18.320343   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-cdfc6fd6c-cbx22-r2jmv, got []"  "node"="md-tvddq-cdfc6fd6c-cbx22-r2jmv"
E0716 17:43:18.341526   10470 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-tvddq-cdfc6fd6c-cbx22-r2jmv for machine md-test/md-tvddq-cdfc6fd6c-cbx22: the cache is not started, can not read objects" "machineset"="md-tvddq-cdfc6fd6c" "namespace"="md-test" 
I0716 17:43:18.369427   10470 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-tvddq-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0716 17:43:18.369487   10470 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-tvddq-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0716 17:43:18.374678   10470 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-tvddq-6657c7fddb" "namespace"="md-test" "machine"="md-tvddq-6657c7fddb-mhvcl"
I0716 17:43:18.485665   10470 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-tvddq-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0716 17:43:18.485720   10470 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-tvddq-cdfc6fd6c" "namespace"="md-test" 
I0716 17:43:18.496643   10470 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-tvddq-cdfc6fd6c-gjk4w\"" "machineset"="md-tvddq-cdfc6fd6c" "namespace"="md-test" 
E0716 17:43:18.566206   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-cdfc6fd6c-gjk4w-659zw, got []"  "node"="md-tvddq-cdfc6fd6c-gjk4w-659zw"
E0716 17:43:18.566430   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-cdfc6fd6c-gjk4w-659zw, got []"  "node"="md-tvddq-cdfc6fd6c-gjk4w-659zw"
E0716 17:43:18.566581   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-cdfc6fd6c-gjk4w-659zw, got []"  "node"="md-tvddq-cdfc6fd6c-gjk4w-659zw"
E0716 17:43:18.670539   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-cdfc6fd6c-gjk4w-659zw, got []"  "node"="md-tvddq-cdfc6fd6c-gjk4w-659zw"
E0716 17:43:18.670620   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-cdfc6fd6c-gjk4w-659zw, got []"  "node"="md-tvddq-cdfc6fd6c-gjk4w-659zw"
E0716 17:43:18.670567   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-cdfc6fd6c-gjk4w-659zw, got []"  "node"="md-tvddq-cdfc6fd6c-gjk4w-659zw"
E0716 17:43:18.670647   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-cdfc6fd6c-gjk4w-659zw, got []"  "node"="md-tvddq-cdfc6fd6c-gjk4w-659zw"
E0716 17:43:18.670647   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-cdfc6fd6c-gjk4w-659zw, got []"  "node"="md-tvddq-cdfc6fd6c-gjk4w-659zw"
E0716 17:43:18.670713   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-cdfc6fd6c-gjk4w-659zw, got []"  "node"="md-tvddq-cdfc6fd6c-gjk4w-659zw"
I0716 17:43:18.708700   10470 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-tvddq-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=1
I0716 17:43:18.708753   10470 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-tvddq-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0716 17:43:18.715733   10470 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-tvddq-6657c7fddb" "namespace"="md-test" "machine"="md-tvddq-6657c7fddb-flwkf"
I0716 17:43:18.743206   10470 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-tvddq-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=3
I0716 17:43:18.743335   10470 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-tvddq-cdfc6fd6c" "namespace"="md-test" 
I0716 17:43:18.753791   10470 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-tvddq-cdfc6fd6c-2z4gg\"" "machineset"="md-tvddq-cdfc6fd6c" "namespace"="md-test" 
E0716 17:43:18.816969   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-cdfc6fd6c-2z4gg-z44pq, got []"  "node"="md-tvddq-cdfc6fd6c-2z4gg-z44pq"
E0716 17:43:18.817085   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-cdfc6fd6c-2z4gg-z44pq, got []"  "node"="md-tvddq-cdfc6fd6c-2z4gg-z44pq"
E0716 17:43:18.817085   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-cdfc6fd6c-2z4gg-z44pq, got []"  "node"="md-tvddq-cdfc6fd6c-2z4gg-z44pq"
E0716 17:43:18.819823   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-cdfc6fd6c-2z4gg-z44pq, got []"  "node"="md-tvddq-cdfc6fd6c-2z4gg-z44pq"
E0716 17:43:18.819926   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-cdfc6fd6c-2z4gg-z44pq, got []"  "node"="md-tvddq-cdfc6fd6c-2z4gg-z44pq"
E0716 17:43:18.819946   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-cdfc6fd6c-2z4gg-z44pq, got []"  "node"="md-tvddq-cdfc6fd6c-2z4gg-z44pq"
E0716 17:43:18.819931   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-cdfc6fd6c-2z4gg-z44pq, got []"  "node"="md-tvddq-cdfc6fd6c-2z4gg-z44pq"
E0716 17:43:18.819992   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-cdfc6fd6c-2z4gg-z44pq, got []"  "node"="md-tvddq-cdfc6fd6c-2z4gg-z44pq"
E0716 17:43:18.819997   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-cdfc6fd6c-2z4gg-z44pq, got []"  "node"="md-tvddq-cdfc6fd6c-2z4gg-z44pq"
I0716 17:43:18.859261   10470 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-tvddq-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=0
I0716 17:43:18.859356   10470 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-tvddq-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0716 17:43:18.865881   10470 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-tvddq-6657c7fddb" "namespace"="md-test" "machine"="md-tvddq-6657c7fddb-lgdrm"
I0716 17:43:18.873728   10470 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-xsrq2" "machine"="test-mhc-machine-rmzck" "namespace"="test-mhc-mksbr" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-n2cf9"}
E0716 17:43:18.916500   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-rmzck\" not found" "controller"="machine" "name"="test-mhc-machine-rmzck" "namespace"="test-mhc-mksbr"
I0716 17:43:18.997050   10470 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-tvddq-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=1
I0716 17:43:18.997109   10470 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-tvddq-74d45c49c5" "namespace"="md-test" 
I0716 17:43:19.014524   10470 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-tvddq-74d45c49c5-kwcdm\"" "machineset"="md-tvddq-74d45c49c5" "namespace"="md-test" 
E0716 17:43:19.059773   10470 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-plfmc/test-cluster-cd4b2"
E0716 17:43:19.089322   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-74d45c49c5-kwcdm-6579v, got []"  "node"="md-tvddq-74d45c49c5-kwcdm-6579v"
E0716 17:43:19.089653   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-74d45c49c5-kwcdm-6579v, got []"  "node"="md-tvddq-74d45c49c5-kwcdm-6579v"
E0716 17:43:19.194392   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-74d45c49c5-kwcdm-6579v, got []"  "node"="md-tvddq-74d45c49c5-kwcdm-6579v"
E0716 17:43:19.194465   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-74d45c49c5-kwcdm-6579v, got []"  "node"="md-tvddq-74d45c49c5-kwcdm-6579v"
E0716 17:43:19.194803   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-74d45c49c5-kwcdm-6579v, got []"  "node"="md-tvddq-74d45c49c5-kwcdm-6579v"
E0716 17:43:19.194886   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-74d45c49c5-kwcdm-6579v, got []"  "node"="md-tvddq-74d45c49c5-kwcdm-6579v"
I0716 17:43:19.236368   10470 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-tvddq-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2
I0716 17:43:19.236426   10470 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-tvddq-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0716 17:43:19.242435   10470 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-tvddq-cdfc6fd6c" "namespace"="md-test" "machine"="md-tvddq-cdfc6fd6c-gjk4w"
I0716 17:43:19.354426   10470 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-tvddq-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=2
I0716 17:43:19.354465   10470 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-tvddq-74d45c49c5" "namespace"="md-test" 
I0716 17:43:19.374010   10470 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-tvddq-74d45c49c5-d94mj\"" "machineset"="md-tvddq-74d45c49c5" "namespace"="md-test" 
E0716 17:43:19.439419   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-74d45c49c5-d94mj-z5pcr, got []"  "node"="md-tvddq-74d45c49c5-d94mj-z5pcr"
E0716 17:43:19.439697   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-74d45c49c5-d94mj-z5pcr, got []"  "node"="md-tvddq-74d45c49c5-d94mj-z5pcr"
E0716 17:43:19.443082   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-74d45c49c5-d94mj-z5pcr, got []"  "node"="md-tvddq-74d45c49c5-d94mj-z5pcr"
E0716 17:43:19.443122   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-74d45c49c5-d94mj-z5pcr, got []"  "node"="md-tvddq-74d45c49c5-d94mj-z5pcr"
E0716 17:43:19.443222   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-74d45c49c5-d94mj-z5pcr, got []"  "node"="md-tvddq-74d45c49c5-d94mj-z5pcr"
E0716 17:43:19.443290   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-74d45c49c5-d94mj-z5pcr, got []"  "node"="md-tvddq-74d45c49c5-d94mj-z5pcr"
I0716 17:43:19.520424   10470 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-tvddq-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1
I0716 17:43:19.520530   10470 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-tvddq-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0716 17:43:19.527284   10470 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-tvddq-cdfc6fd6c" "namespace"="md-test" "machine"="md-tvddq-cdfc6fd6c-2z4gg"
I0716 17:43:19.555960   10470 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-tvddq-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0716 17:43:19.556012   10470 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-tvddq-74d45c49c5" "namespace"="md-test" 
I0716 17:43:19.569755   10470 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-tvddq-74d45c49c5-9wmck\"" "machineset"="md-tvddq-74d45c49c5" "namespace"="md-test" 
E0716 17:43:19.725090   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-74d45c49c5-9wmck-lstg5, got []"  "node"="md-tvddq-74d45c49c5-9wmck-lstg5"
E0716 17:43:19.725118   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-74d45c49c5-9wmck-lstg5, got []"  "node"="md-tvddq-74d45c49c5-9wmck-lstg5"
E0716 17:43:19.728205   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-74d45c49c5-9wmck-lstg5, got []"  "node"="md-tvddq-74d45c49c5-9wmck-lstg5"
E0716 17:43:19.728275   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-74d45c49c5-9wmck-lstg5, got []"  "node"="md-tvddq-74d45c49c5-9wmck-lstg5"
E0716 17:43:19.728374   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-74d45c49c5-9wmck-lstg5, got []"  "node"="md-tvddq-74d45c49c5-9wmck-lstg5"
E0716 17:43:19.728446   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-tvddq-74d45c49c5-9wmck-lstg5, got []"  "node"="md-tvddq-74d45c49c5-9wmck-lstg5"
I0716 17:43:19.748477   10470 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-tvddq-74d45c49c5,md-tvddq-cdfc6fd6c;Worker machines: md-tvddq-74d45c49c5-kwcdm,md-tvddq-cdfc6fd6c-cbx22,md-tvddq-6657c7fddb-9llxh,md-tvddq-6657c7fddb-cp6gx,md-tvddq-74d45c49c5-d94mj,md-tvddq-74d45c49c5-9wmck" "indirect descendants count"=8
I0716 17:43:19.752798   10470 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-tvddq-74d45c49c5,md-tvddq-cdfc6fd6c;Worker machines: md-tvddq-74d45c49c5-d94mj,md-tvddq-74d45c49c5-9wmck,md-tvddq-74d45c49c5-kwcdm,md-tvddq-cdfc6fd6c-cbx22,md-tvddq-6657c7fddb-9llxh,md-tvddq-6657c7fddb-cp6gx" "indirect descendants count"=8
•I0716 17:43:19.828285   10470 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-9pslk" "namespace"="ms-test" "creating"=2 "need"=2
I0716 17:43:19.828339   10470 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-9pslk" "namespace"="ms-test" 
I0716 17:43:19.852671   10470 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-9pslk-7gnws\"" "machineset"="ms-9pslk" "namespace"="ms-test" 
I0716 17:43:19.852755   10470 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-9pslk" "namespace"="ms-test" 
... skipping 2 lines ...
I0716 17:43:19.936043   10470 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-tvddq-6657c7fddb-9llxh" "namespace"="md-test" 
I0716 17:43:19.953573   10470 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-tvddq-6657c7fddb-cp6gx" "namespace"="md-test" 
I0716 17:43:19.953678   10470 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-tvddq-6657c7fddb-cp6gx" "namespace"="md-test" 
I0716 17:43:19.971112   10470 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-9pslk" "namespace"="ms-test" "creating"=1 "need"=2
I0716 17:43:19.971183   10470 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-9pslk" "namespace"="ms-test" 
I0716 17:43:19.993807   10470 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-9pslk-vxt6l\"" "machineset"="ms-9pslk" "namespace"="ms-test" 
E0716 17:43:20.047145   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-tvddq-cdfc6fd6c-cbx22\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-tvddq-cdfc6fd6c-cbx22" "namespace"="md-test"
E0716 17:43:20.085920   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-9pslk-vxt6l-r4rct, got []"  "node"="ms-9pslk-vxt6l-r4rct"
E0716 17:43:20.086259   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-9pslk-vxt6l-r4rct, got []"  "node"="ms-9pslk-vxt6l-r4rct"
E0716 17:43:20.089504   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-9pslk-vxt6l-r4rct, got []"  "node"="ms-9pslk-vxt6l-r4rct"
E0716 17:43:20.089537   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-9pslk-vxt6l-r4rct, got []"  "node"="ms-9pslk-vxt6l-r4rct"
E0716 17:43:20.089651   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-9pslk-vxt6l-r4rct, got []"  "node"="ms-9pslk-vxt6l-r4rct"
E0716 17:43:20.089703   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-9pslk-vxt6l-r4rct, got []"  "node"="ms-9pslk-vxt6l-r4rct"
E0716 17:43:20.126284   10470 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-9pslk-vxt6l-r4rct for machine ms-test/ms-9pslk-vxt6l: the cache is not started, can not read objects" "machineset"="ms-9pslk" "namespace"="ms-test" 
E0716 17:43:20.133930   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-9pslk-2jf2r-n4ldw, got []"  "node"="ms-9pslk-2jf2r-n4ldw"
E0716 17:43:20.134511   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-9pslk-2jf2r-n4ldw, got []"  "node"="ms-9pslk-2jf2r-n4ldw"
E0716 17:43:20.137367   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-9pslk-2jf2r-n4ldw, got []"  "node"="ms-9pslk-2jf2r-n4ldw"
E0716 17:43:20.137431   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-9pslk-2jf2r-n4ldw, got []"  "node"="ms-9pslk-2jf2r-n4ldw"
E0716 17:43:20.137583   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-9pslk-2jf2r-n4ldw, got []"  "node"="ms-9pslk-2jf2r-n4ldw"
E0716 17:43:20.137659   10470 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-9pslk-2jf2r-n4ldw, got []"  "node"="ms-9pslk-2jf2r-n4ldw"
I0716 17:43:20.269407   10470 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-9pslk-vxt6l,ms-9pslk-2jf2r" "indirect descendants count"=2
I0716 17:43:20.273619   10470 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-9pslk-vxt6l,ms-9pslk-2jf2r" "indirect descendants count"=2
••E0716 17:43:20.404648   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-fltsh\" not found" "controller"="cluster" "name"="test1-fltsh" "namespace"="default"
I0716 17:43:21.052512   10470 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-tvddq-6657c7fddb-9llxh" "namespace"="md-test" 
I0716 17:43:21.052564   10470 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-tvddq-6657c7fddb-9llxh" "namespace"="md-test" 
I0716 17:43:21.057860   10470 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-tvddq-6657c7fddb-cp6gx" "namespace"="md-test" 
I0716 17:43:21.057915   10470 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-tvddq-6657c7fddb-cp6gx" "namespace"="md-test" 
E0716 17:43:21.093260   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-tvddq-74d45c49c5-kwcdm\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-tvddq-74d45c49c5-kwcdm" "namespace"="md-test"
E0716 17:43:21.433812   10470 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-vgllg/test-cluster-dt8wf"
I0716 17:43:21.523995   10470 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-k4z4q" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
•I0716 17:43:21.647592   10470 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-k4z4q" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0716 17:43:21.652270   10470 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-k4z4q" "namespace"="default"
E0716 17:43:22.126224   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-tvddq-74d45c49c5-d94mj\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-tvddq-74d45c49c5-d94mj" "namespace"="md-test"
E0716 17:43:22.667562   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-k4z4q: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-k4z4q" "namespace"="default"
•E0716 17:43:23.224008   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-tvddq-cdfc6fd6c-cbx22\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-tvddq-cdfc6fd6c-cbx22" "namespace"="md-test"
E0716 17:43:23.681628   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-wcv5j\" not found" "controller"="cluster" "name"="test3-wcv5j" "namespace"="default"
E0716 17:43:24.230577   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-tvddq-74d45c49c5-kwcdm\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-tvddq-74d45c49c5-kwcdm" "namespace"="md-test"
E0716 17:43:24.682480   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-k4z4q: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-k4z4q" "namespace"="default"
I0716 17:43:25.236139   10470 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-tvddq-6657c7fddb-9llxh" "namespace"="md-test" 
I0716 17:43:25.236191   10470 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-tvddq-6657c7fddb-9llxh" "namespace"="md-test" 
I0716 17:43:25.242256   10470 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-tvddq-6657c7fddb-cp6gx" "namespace"="md-test" 
I0716 17:43:25.242360   10470 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-tvddq-6657c7fddb-cp6gx" "namespace"="md-test" 
E0716 17:43:25.248013   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-tvddq-74d45c49c5-d94mj\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-tvddq-74d45c49c5-d94mj" "namespace"="md-test"
E0716 17:43:25.693397   10470 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-mksbr/test-cluster-xsrq2"
E0716 17:43:25.702069   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-k4z4q: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-k4z4q" "namespace"="default"
•E0716 17:43:26.315795   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-tvddq-cdfc6fd6c-cbx22\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-tvddq-cdfc6fd6c-cbx22" "namespace"="md-test"
I0716 17:43:26.702925   10470 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-tvddq-74d45c49c5,md-tvddq-cdfc6fd6c;Worker machines: md-tvddq-cdfc6fd6c-cbx22,md-tvddq-6657c7fddb-9llxh,md-tvddq-6657c7fddb-cp6gx,md-tvddq-74d45c49c5-d94mj,md-tvddq-74d45c49c5-9wmck,md-tvddq-74d45c49c5-kwcdm" "indirect descendants count"=8
I0716 17:43:26.703362   10470 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-9pslk-vxt6l,ms-9pslk-2jf2r" "indirect descendants count"=2
E0716 17:43:26.707688   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-mct52: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-mct52" "namespace"="default"
E0716 17:43:27.322304   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-tvddq-74d45c49c5-kwcdm\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-tvddq-74d45c49c5-kwcdm" "namespace"="md-test"
E0716 17:43:27.709121   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-k4z4q: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-k4z4q" "namespace"="default"
E0716 17:43:28.328462   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-tvddq-74d45c49c5-d94mj\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-tvddq-74d45c49c5-d94mj" "namespace"="md-test"
E0716 17:43:28.722353   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-mct52: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-mct52" "namespace"="default"
•E0716 17:43:29.329090   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-8fqqv\" for machine \"test-mhc-machine-jzkh2\" in namespace \"test-mhc-snlsv\": Cluster.cluster.x-k8s.io \"test-cluster-8fqqv\" not found" "controller"="machine" "name"="test-mhc-machine-jzkh2" "namespace"="test-mhc-snlsv"
E0716 17:43:29.723181   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-k4z4q: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-k4z4q" "namespace"="default"
I0716 17:43:30.334967   10470 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-tvddq-6657c7fddb-9llxh" "namespace"="md-test" 
I0716 17:43:30.335015   10470 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-tvddq-6657c7fddb-9llxh" "namespace"="md-test" 
I0716 17:43:30.340762   10470 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-tvddq-6657c7fddb-cp6gx" "namespace"="md-test" 
I0716 17:43:30.340808   10470 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-tvddq-6657c7fddb-cp6gx" "namespace"="md-test" 
E0716 17:43:30.360239   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-tvddq-cdfc6fd6c-cbx22\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-tvddq-cdfc6fd6c-cbx22" "namespace"="md-test"
E0716 17:43:30.723988   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-mct52: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-mct52" "namespace"="default"
E0716 17:43:31.366574   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-tvddq-74d45c49c5-kwcdm\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-tvddq-74d45c49c5-kwcdm" "namespace"="md-test"
E0716 17:43:31.734465   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-k4z4q: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-k4z4q" "namespace"="default"
E0716 17:43:32.374451   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-tvddq-74d45c49c5-d94mj\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-tvddq-74d45c49c5-d94mj" "namespace"="md-test"
E0716 17:43:32.735329   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-mct52: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-mct52" "namespace"="default"
E0716 17:43:33.385530   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-tvddq-cdfc6fd6c-cbx22\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-tvddq-cdfc6fd6c-cbx22" "namespace"="md-test"
I0716 17:43:33.736121   10470 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-tvddq-74d45c49c5,md-tvddq-cdfc6fd6c;Worker machines: md-tvddq-74d45c49c5-kwcdm,md-tvddq-cdfc6fd6c-cbx22,md-tvddq-6657c7fddb-9llxh,md-tvddq-6657c7fddb-cp6gx,md-tvddq-74d45c49c5-d94mj,md-tvddq-74d45c49c5-9wmck" "indirect descendants count"=8
I0716 17:43:33.736481   10470 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-9pslk-vxt6l,ms-9pslk-2jf2r" "indirect descendants count"=2
E0716 17:43:33.736965   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-k4z4q: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-k4z4q" "namespace"="default"
I0716 17:43:34.390901   10470 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-tvddq-6657c7fddb-9llxh" "namespace"="md-test" 
I0716 17:43:34.390948   10470 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-tvddq-6657c7fddb-9llxh" "namespace"="md-test" 
I0716 17:43:34.394913   10470 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-tvddq-6657c7fddb-cp6gx" "namespace"="md-test" 
I0716 17:43:34.394949   10470 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-tvddq-6657c7fddb-cp6gx" "namespace"="md-test" 
E0716 17:43:34.400126   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-tvddq-74d45c49c5-kwcdm\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-tvddq-74d45c49c5-kwcdm" "namespace"="md-test"
E0716 17:43:34.737769   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-mct52: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-mct52" "namespace"="default"
E0716 17:43:35.420477   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-tvddq-74d45c49c5-d94mj\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-tvddq-74d45c49c5-d94mj" "namespace"="md-test"
E0716 17:43:35.738534   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-k4z4q: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-k4z4q" "namespace"="default"
E0716 17:43:36.426824   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-tvddq-cdfc6fd6c-cbx22\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-tvddq-cdfc6fd6c-cbx22" "namespace"="md-test"
E0716 17:43:36.739321   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-mct52: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-mct52" "namespace"="default"
E0716 17:43:37.433829   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-tvddq-74d45c49c5-kwcdm\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-tvddq-74d45c49c5-kwcdm" "namespace"="md-test"
E0716 17:43:37.740153   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-mct52: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-mct52" "namespace"="default"
I0716 17:43:38.439448   10470 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-tvddq-6657c7fddb-9llxh" "namespace"="md-test" 
I0716 17:43:38.439573   10470 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-tvddq-6657c7fddb-9llxh" "namespace"="md-test" 
I0716 17:43:38.444516   10470 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-tvddq-6657c7fddb-cp6gx" "namespace"="md-test" 
I0716 17:43:38.444565   10470 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-tvddq-6657c7fddb-cp6gx" "namespace"="md-test" 
I0716 17:43:38.462572   10470 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-2wf7j" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0716 17:43:38.480019   10470 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-2wf7j" "namespace"="default" 
E0716 17:43:38.495119   10470 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-2wf7j" "namespace"="default"
E0716 17:43:38.741047   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-k4z4q: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-k4z4q" "namespace"="default"
E0716 17:43:39.501098   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-tvddq-74d45c49c5-d94mj\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-tvddq-74d45c49c5-d94mj" "namespace"="md-test"
E0716 17:43:39.741877   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-mct52: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-mct52" "namespace"="default"
E0716 17:43:40.506513   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-tvddq-cdfc6fd6c-cbx22\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-tvddq-cdfc6fd6c-cbx22" "namespace"="md-test"
I0716 17:43:40.742741   10470 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-tvddq-cdfc6fd6c,md-tvddq-74d45c49c5;Worker machines: md-tvddq-6657c7fddb-9llxh,md-tvddq-6657c7fddb-cp6gx,md-tvddq-74d45c49c5-d94mj,md-tvddq-74d45c49c5-9wmck,md-tvddq-74d45c49c5-kwcdm,md-tvddq-cdfc6fd6c-cbx22" "indirect descendants count"=8
I0716 17:43:40.743120   10470 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-9pslk-2jf2r,ms-9pslk-vxt6l" "indirect descendants count"=2
E0716 17:43:40.743523   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-mct52: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-mct52" "namespace"="default"
E0716 17:43:41.511961   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-tvddq-74d45c49c5-kwcdm\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-tvddq-74d45c49c5-kwcdm" "namespace"="md-test"
E0716 17:43:41.744409   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-k4z4q: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-k4z4q" "namespace"="default"
I0716 17:43:42.526144   10470 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-2wf7j" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0716 17:43:42.526442   10470 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-2wf7j" "namespace"="default" "noderef"="id-node-1"
E0716 17:43:42.540863   10470 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-2wf7j" "namespace"="default"
E0716 17:43:42.745355   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-mct52: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-mct52" "namespace"="default"
I0716 17:43:43.547638   10470 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-tvddq-6657c7fddb-9llxh" "namespace"="md-test" 
I0716 17:43:43.547706   10470 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-tvddq-6657c7fddb-9llxh" "namespace"="md-test" 
I0716 17:43:43.552966   10470 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-tvddq-6657c7fddb-cp6gx" "namespace"="md-test" 
I0716 17:43:43.553048   10470 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-tvddq-6657c7fddb-cp6gx" "namespace"="md-test" 
E0716 17:43:43.558490   10470 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-tvddq-74d45c49c5-d94mj\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-tvddq-74d45c49c5-d94mj" "namespace"="md-test"

------------------------------
• [SLOW TEST:14.978 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 25 lines ...
I0716 17:43:43.779288   10470 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"
•I0716 17:43:43.780899   10470 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"
I0716 17:43:43.781671   10470 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"
I0716 17:43:43.782248   10470 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0716 17:43:43.782277   10470 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0716 17:43:43.782727   10470 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0716 17:43:43.784048   10470 machine_controller.go:494]  "msg"="Error creating a remote client while deleting Machine, won't retry" "error"="failed to create REST configuration for Cluster default/test-cluster: invalid configuration: no configuration has been provided" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node" 
•

Ran 16 of 16 Specs in 26.042 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (26.04s)
PASS
Tearing down test suite
I0716 17:43:43.785758   10470 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
I0716 17:43:43.785761   10470 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I0716 17:43:43.785792   10470 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0716 17:43:43.785808   10470 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
E0716 17:43:43.785886   10470 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0716 17:43:43.785959   10470 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-955911127/tls.crt: no such file or directory"  
I0716 17:43:43.785761   10470 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0716 17:43:43.785783   10470 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0716 17:43:43.786158   10470 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0716 17:43:43.821543   10470 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:44573/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1306&timeout=10s&timeoutSeconds=428&watch=true: dial tcp 127.0.0.1:44573: connect: connection refused
E0716 17:43:43.821543   10470 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:44573/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1306&timeout=10s&timeoutSeconds=354&watch=true: dial tcp 127.0.0.1:44573: connect: connection refused
E0716 17:43:43.822455   10470 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:44573/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1306&timeout=10s&timeoutSeconds=569&watch=true: dial tcp 127.0.0.1:44573: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	74.346s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 265 lines ...
•I0716 17:42:42.030407   11036 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0716 17:42:42.047931   11036 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":{}}}
I0716 17:42:42.248383   11036 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0716 17:42:42.248464   11036 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0716 17:42:42.248547   11036 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0716 17:42:42.775686   11036 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
E0716 17:42:44.851717   11036 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-gk9m4/test-cluster"
•E0716 17:42:45.290444   11036 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-t9qq5/test-cluster"
•E0716 17:42:45.861083   11036 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:39095/?timeout=50ms: dial tcp 127.0.0.1:39095: connect: connection refused"  "cluster"="cluster-cache-test-5b8ns/test-cluster"
•I0716 17:42:46.113899   11036 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0716 17:42:46.176154   11036 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:38289/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=146&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:38289: connect: connection refused


Ran 5 of 5 Specs in 14.678 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (14.68s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	14.821s
?   	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
I0716 17:42:52.157444   11672 controller.go:130]  "msg"="Cluster Controller has not yet set OwnerRef" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcileNoClusterOwnerRef (0.00s)
=== RUN   TestReconcileNoKCP
--- PASS: TestReconcileNoKCP (0.00s)
=== RUN   TestReconcileNoCluster
E0716 17:42:52.158440   11672 controller.go:126]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="clusters.cluster.x-k8s.io \"foo\" not found" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcileNoCluster (0.00s)
=== RUN   TestReconcilePaused
I0716 17:42:52.158982   11672 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I0716 17:42:52.159107   11672 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcilePaused (0.00s)
=== RUN   TestReconcileClusterNoEndpoints
... skipping 192 lines ...
    --- PASS: TestSelectMachineForScaleDown/when_there_is_an_up_to_date_machine_with_delete_annotation,_while_there_are_any_outdated_machines_without_annotatio_that_still_exist,_it_returns_oldest_marked_machine_first (0.00s)
=== RUN   TestPreflightChecks
=== RUN   TestPreflightChecks/control_plane_without_machines_(not_initialized)_should_pass
=== RUN   TestPreflightChecks/control_plane_with_a_deleting_machine_should_requeue
I0716 17:43:04.885696   11672 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
I0716 17:43:04.885832   11672 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: 1626457360
Will run 1 of 1 specs

E0716 17:43:04.929789   11672 controller.go:126]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="Cluster.cluster.x-k8s.io \"kcp-foo-58vqis\" not found" "kubeadmControlPlane"="kcp-foo-58vqis" "namespace"="test" 
•

Ran 1 of 1 Specs in 0.039 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (0.04s)
=== RUN   TestKubeadmControlPlaneReconciler_upgradeControlPlane
I0716 17:43:04.931154   11672 controller.go:246]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-eyvs6d" "kubeadmControlPlane"="kcp-foo-eyvs6d" "namespace"="test" 
I0716 17:43:06.728618   11672 controller.go:331]  "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-eyvs6d" "kubeadmControlPlane"="kcp-foo-eyvs6d" "namespace"="test" "needRollout"=["kcp-foo-eyvs6d-58rsh"]
I0716 17:43:06.728799   11672 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-eyvs6d" "kubeadmControlPlane"="kcp-foo-eyvs6d" "namespace"="test" "failures"="[machine kcp-foo-eyvs6d-67gn6 does not have APIServerPodHealthy condition, machine kcp-foo-eyvs6d-67gn6 does not have ControllerManagerPodHealthy condition, machine kcp-foo-eyvs6d-67gn6 does not have SchedulerPodHealthy condition, machine kcp-foo-eyvs6d-67gn6 does not have EtcdPodHealthy condition, machine kcp-foo-eyvs6d-67gn6 does not have EtcdMemberHealthy condition]"
--- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (1.80s)
... skipping 60 lines ...
==================================
Random Seed: 1626457359
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: 1626457359
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 117 lines ...
    --- PASS: TestValidateCoreDNSImageTag/fromVer_is_equal_to_toVer (0.00s)
    --- PASS: TestValidateCoreDNSImageTag/fromVer_is_lower_but_has_meta (0.00s)
    --- PASS: TestValidateCoreDNSImageTag/fromVer_is_lower_and_has_meta_and_leading_v (0.00s)
    --- PASS: TestValidateCoreDNSImageTag/fromVer_is_lower,_toVer_has_meta_and_leading_v (0.00s)
=== RUN   TestUpdateCoreDNSClusterRole
=== RUN   TestUpdateCoreDNSClusterRole/does_not_patch_ClusterRole:_invalid_CoreDNS_tag
panic: failed to add object &ClusterRole{ObjectMeta:{system:coredns  kube-system    0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] []  []},Rules:[]PolicyRule{PolicyRule{Verbs:[list watch],APIGroups:[],Resources:[endpoints services pods namespaces],ResourceNames:[],NonResourceURLs:[],},PolicyRule{Verbs:[get],APIGroups:[],Resources:[nodes],ResourceNames:[],NonResourceURLs:[],},},AggregationRule:nil,} to fake client: no kind is registered for the type v1.ClusterRole in scheme "pkg/runtime/scheme.go:101" [recovered]
	panic: failed to add object &ClusterRole{ObjectMeta:{system:coredns  kube-system    0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] []  []},Rules:[]PolicyRule{PolicyRule{Verbs:[list watch],APIGroups:[],Resources:[endpoints services pods namespaces],ResourceNames:[],NonResourceURLs:[],},PolicyRule{Verbs:[get],APIGroups:[],Resources:[nodes],ResourceNames:[],NonResourceURLs:[],},},AggregationRule:nil,} to fake client: no kind is registered for the type v1.ClusterRole in scheme "pkg/runtime/scheme.go:101"

goroutine 2466 [running]:
testing.tRunner.func1(0xc00070af00)
	/usr/local/go/src/testing/testing.go:874 +0x3a3
panic(0x18f3560, 0xc000906780)
	/usr/local/go/src/runtime/panic.go:679 +0x1b2
... skipping 2 lines ...
sigs.k8s.io/cluster-api/controlplane/kubeadm/internal.TestUpdateCoreDNSClusterRole.func1(0xc00070af00)
	/home/prow/go/src/sigs.k8s.io/cluster-api/controlplane/kubeadm/internal/workload_cluster_coredns_test.go:610 +0x152
testing.tRunner(0xc00070af00, 0xc000906620)
	/usr/local/go/src/testing/testing.go:909 +0xc9
created by testing.(*T).Run
	/usr/local/go/src/testing/testing.go:960 +0x350
FAIL	sigs.k8s.io/cluster-api/controlplane/kubeadm/internal	12.530s
=== RUN   TestEtcdMembers_WithErrors
--- PASS: TestEtcdMembers_WithErrors (0.00s)
=== RUN   TestEtcdMembers_WithSuccess
--- PASS: TestEtcdMembers_WithSuccess (0.00s)
PASS
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/internal/etcd	0.031s
... skipping 286 lines ...
I0716 17:42:57.196892   11902 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0716 17:42:57.197450   11902 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"ConfigMap","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0716 17:42:57.297902   11902 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0716 17:42:57.398359   11902 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0716 17:42:57.398423   11902 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0716 17:42:57.517475   11902 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-q2ubw0"} 
E0716 17:42:57.542861   11902 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"
•I0716 17:42:58.604086   11902 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-en2xoo"} 
E0716 17:42:58.642485   11902 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"
•E0716 17:42:59.732922   11902 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"
E0716 17:43:00.757984   11902 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"
•E0716 17:43:01.897575   11902 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"
•E0716 17:43:02.927165   11902 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"
E0716 17:43:03.943186   11902 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"
•I0716 17:43:03.943958   11902 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 
I0716 17:43:03.944034   11902 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
I0716 17:43:03.944074   11902 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 5 of 5 Specs in 17.684 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (17.68s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/addons/controllers	17.778s
?   	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
E0716 17:42:52.378383   12230 machinepool_controller_phases.go:237]  "msg"="MachinePool infrastructure reference has been deleted after being ready, setting failure state" "error"="could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureConfig \"infra-config1\" for MachinePool \"machinepool-test\" in namespace \"default\", requeuing: failed to retrieve InfrastructureConfig external object \"default\"/\"infra-config1\": infrastructureconfigs.infrastructure.cluster.x-k8s.io \"infra-config1\" not found" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
=== RUN   TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused
--- PASS: TestReconcileMachinePoolInfrastructure (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestMachinePoolFinalizer
... skipping 96 lines ...
•I0716 17:43:03.478657   12230 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••I0716 17:43:03.480997   12230 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0716 17:43:03.527668   12230 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinepool" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}


Ran 9 of 9 Specs in 11.060 seconds
SUCCESS! -- 9 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (11.06s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/controllers	11.328s
?   	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 ...
I0716 17:43:21.998389   15034 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=41607
I0716 17:43:21.998466   15034 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
••••••••••••••I0716 17:43:22.880510   15034 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 14 of 14 Specs in 8.292 seconds
SUCCESS! -- 14 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestPatch (8.29s)
=== 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.036s
FAIL
make: *** [Makefile:116: test] Error 1
+ EXIT_VALUE=2
+ set +o xtrace