periodic-cluster-api-test-release-0-3 #1592360158221045760
Recent runs || View in Spyglass
| Result | FAILURE |
| Tests | 0 failed / 0 succeeded |
| Started | |
| Elapsed | 4m27s |
| Revision | release-0.3 |
... skipping 773 lines ... I1115 03:35:28.756789 8308 server.go:121] controller-runtime/webhook "msg"="registering webhook" "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset" I1115 03:35:28.756907 8308 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server" I1115 03:35:28.757769 8308 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate" I1115 03:35:28.757978 8308 server.go:199] controller-runtime/webhook "msg"="serving webhook server" "host"="" "port"=46305 I1115 03:35:28.758143 8308 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher" I1115 03:35:29.629110 8308 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" [32m•[0mE1115 03:35:29.638516 8308 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory" E1115 03:35:29.638560 8308 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-710672875/tls.crt: no such file or directory" E1115 03:35:29.638579 8308 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory" E1115 03:35:29.638598 8308 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-710672875/tls.crt: no such file or directory" I1115 03:35:29.638955 8308 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server" [1m[32mRan 1 of 1 Specs in 13.834 seconds[0m [1m[32mSUCCESS![0m -- [32m[1m1 Passed[0m | [91m[1m0 Failed[0m | [33m[1m0 Pending[0m | [36m[1m0 Skipped[0m --- PASS: TestAPIs (13.83s) PASS ok sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers 45.749s === RUN TestNewInitControlPlaneAdditionalFileEncodings --- PASS: TestNewInitControlPlaneAdditionalFileEncodings (0.00s) === RUN TestNewInitControlPlaneCommands ... skipping 316 lines ... === RUN Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined --- PASS: Test_clusterctlClient_GetProvidersConfig (0.00s) --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers (0.00s) --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined (0.00s) === RUN Test_clusterctlClient_GetProviderComponents === RUN Test_clusterctlClient_GetProviderComponents/Pass === RUN Test_clusterctlClient_GetProviderComponents/Fail --- PASS: Test_clusterctlClient_GetProviderComponents (0.00s) --- PASS: Test_clusterctlClient_GetProviderComponents/Pass (0.00s) --- PASS: Test_clusterctlClient_GetProviderComponents/Fail (0.00s) === RUN Test_getComponentsByName_withEmptyVariables --- PASS: Test_getComponentsByName_withEmptyVariables (0.00s) === RUN Test_clusterctlClient_templateOptionsToVariables === RUN Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_template_options) === RUN Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_env_variables) === RUN Test_clusterctlClient_templateOptionsToVariables/pass_(using_defaults_for_machine_counts) ... skipping 1398 lines ... I1115 03:35:17.244257 10495 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":{}}} I1115 03:35:17.244351 10495 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":{}}} I1115 03:35:17.244417 10495 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}}} I1115 03:35:17.244463 10495 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" I1115 03:35:17.244510 10495 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1 I1115 03:35:17.249393 10495 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinehealthcheck" "worker count"=1 2022/11/15 03:35:17 http: TLS handshake error from 127.0.0.1:33604: 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 I1115 03:35:17.543402 10495 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" I1115 03:35:17.567772 10495 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 I1115 03:35:17.617253 10495 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 I1115 03:35:17.619920 10495 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" E1115 03:35:17.620371 10495 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 I1115 03:35:17.621098 10495 conversion.go:64] "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config" --- PASS: TestReconcileInfrastructure (0.01s) --- PASS: TestReconcileInfrastructure/new_machine,_infrastructure_config_ready (0.00s) --- PASS: TestReconcileInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machine_is_running,_infra_object_is_deleted,_expect_failed (0.00s) --- PASS: TestReconcileInfrastructure/infrastructure_ref_is_paused (0.00s) === RUN TestWatches I1115 03:35:18.065888 10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={} E1115 03:35:18.069354 10495 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine" "node"="node-1" I1115 03:35:18.081369 10495 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-5tcf5" "namespace"="test-machine-watches-45dld" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine" I1115 03:35:18.081507 10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}} I1115 03:35:18.195543 10495 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-5tcf5" "namespace"="test-machine-watches-45dld" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine" I1115 03:35:18.195681 10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}} I1115 03:35:18.296476 10495 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-5tcf5" "namespace"="test-machine-watches-45dld" "noderef"="node-1" E1115 03:35:18.321046 10495 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine" "node"="node-1" E1115 03:35:18.321124 10495 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine" "node"="node-1" E1115 03:35:18.383337 10495 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-5tcf5\" in namespace \"test-machine-watches-45dld\", requeuing: requeue in 1s" E1115 03:35:18.407204 10495 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-5tcf5\" in namespace \"test-machine-watches-45dld\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-5tcf5\" in namespace \"test-machine-watches-45dld\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-5tcf5" "namespace"="test-machine-watches-45dld" --- PASS: TestWatches (0.83s) === 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 I1115 03:35:18.538851 10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-9r7v5" "namespace"="test-machine-watches-45dld" "count"=1 I1115 03:35:18.538913 10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-9r7v5" "namespace"="test-machine-watches-45dld" "descendants"="Worker machines: machine-created-5tcf5" "indirect descendants count"=0 I1115 03:35:18.554138 10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-9r7v5" "namespace"="test-machine-watches-45dld" "count"=1 I1115 03:35:18.554199 10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-9r7v5" "namespace"="test-machine-watches-45dld" "descendants"="Worker machines: machine-created-5tcf5" "indirect descendants count"=0 I1115 03:35:19.407683 10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-9r7v5" "machine"="machine-created-5tcf5" "namespace"="test-machine-watches-45dld" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"cef0e13e-1d7b-4bad-a2ca-ca2bdf449191","apiVersion":"v1"} E1115 03:35:19.453322 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-5tcf5\" not found" "controller"="machine" "name"="machine-created-5tcf5" "namespace"="test-machine-watches-45dld" E1115 03:35:20.498866 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-qrfq6\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-cbxms\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-cbxms: secrets \"machine-reconcile-cbxms-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-qrfq6" "namespace"="default" I1115 03:35:21.499451 10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-cbxms" "machine"="machine-created-qrfq6" "namespace"="default" "cause"="noderef is nil" "node"=null I1115 03:35:21.560043 10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-cbxms" "machine"="machine-created-qrfq6" "namespace"="default" "cause"="noderef is nil" "node"=null I1115 03:35:21.582954 10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-cbxms" "machine"="machine-created-qrfq6" "namespace"="default" "cause"="noderef is nil" "node"=null E1115 03:35:21.619383 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-qrfq6\" not found" "controller"="machine" "name"="machine-created-qrfq6" "namespace"="default" --- PASS: TestMachine_Reconcile (3.18s) --- PASS: TestMachine_Reconcile/reconcile_create (3.18s) === RUN TestMachineFinalizer === RUN TestMachineFinalizer/should_add_a_machine_finalizer_to_the_machine_if_it_doesn't_have_one === RUN TestMachineFinalizer/should_append_the_machine_finalizer_to_the_machine_if_it_already_has_a_finalizer --- PASS: TestMachineFinalizer (0.00s) ... skipping 15 lines ... --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner (0.00s) === RUN TestReconcileRequest === RUN TestReconcileRequest/machine_should_be_created I1115 03:35:21.644809 10495 conversion.go:64] "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="created" "namespace"="default" "err"="cannot create a metadata client without a rest config" === RUN TestReconcileRequest/machine_should_be_updated I1115 03:35:21.649214 10495 conversion.go:64] "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="updated" "namespace"="default" "err"="cannot create a metadata client without a rest config" E1115 03:35:21.652334 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-cbxms\" not found" "controller"="cluster" "name"="machine-reconcile-cbxms" "namespace"="default" === RUN TestReconcileRequest/machine_should_be_deleted I1115 03:35:21.654016 10495 machine_controller.go:305] "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="deleted" "namespace"="default" "cause"="noderef is nil" "node"=null --- PASS: TestReconcileRequest (0.02s) --- PASS: TestReconcileRequest/machine_should_be_created (0.00s) --- PASS: TestReconcileRequest/machine_should_be_updated (0.00s) --- PASS: TestReconcileRequest/machine_should_be_deleted (0.01s) ... skipping 109 lines ... --- PASS: TestMachineDeploymentSyncStatus/machine_set_failed (0.00s) --- PASS: TestMachineDeploymentSyncStatus/all_machines_are_running (0.00s) === RUN TestMachineHealthCheck_Reconcile === RUN TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist I1115 03:35:21.821278 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqfzq" "namespace"="test-mhc-r7qjm" I1115 03:35:21.835871 10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={} E1115 03:35:21.836919 10495 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-fvqzd\" not found" "cluster"="test-mhc-r7qjm/test-cluster-fvqzd" === RUN TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value E1115 03:35:21.849307 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-xqfzq\" not found" "controller"="machinehealthcheck" "name"="test-mhc-xqfzq" "namespace"="test-mhc-r7qjm" === 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 I1115 03:35:22.849593 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xqfzq" "namespace"="test-mhc-r7qjm" I1115 03:35:22.849694 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x7vdt" "namespace"="test-mhc-776sk" I1115 03:35:22.849722 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-swxpt" "namespace"="test-mhc-c74qj" I1115 03:35:22.849746 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s7nwq" "namespace"="test-mhc-52vqx" I1115 03:35:22.885260 10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={} I1115 03:35:23.008003 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s7nwq" "namespace"="test-mhc-52vqx" I1115 03:35:23.056333 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-s7nwq" "namespace"="test-mhc-52vqx" === RUN TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones E1115 03:35:23.096603 10495 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="test-mhc-52vqx/test-cluster-cjr5c" E1115 03:35:23.099794 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-cjr5c\" not found" "controller"="cluster" "name"="test-cluster-cjr5c" "namespace"="test-mhc-52vqx" I1115 03:35:23.103261 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gngbq" "namespace"="test-mhc-ldr6v" I1115 03:35:23.116778 10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={} I1115 03:35:23.234763 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gngbq" "namespace"="test-mhc-ldr6v" E1115 03:35:23.308566 10495 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="test-mhc-ldr6v/test-cluster-m5dlq" I1115 03:35:23.312996 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gngbq" "namespace"="test-mhc-ldr6v" === RUN TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy I1115 03:35:23.337265 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ptmvw" "namespace"="test-mhc-lgbtz" inframachine created: test-mhc-machine-infra-6nlm2 machine created: test-mhc-machine-7k4tz I1115 03:35:23.361149 10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={} node created: test-mhc-node-85bdh E1115 03:35:23.460924 10495 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine" "node"="test-mhc-node-85bdh" E1115 03:35:23.461784 10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-85bdh, got []" "node"="test-mhc-node-85bdh" I1115 03:35:23.461809 10495 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-lgbtz/test-mhc-ptmvw/test-mhc-machine-7k4tz/" I1115 03:35:23.461964 10495 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-7k4tz" "namespace"="test-mhc-lgbtz" "noderef"="test-mhc-node-85bdh" E1115 03:35:23.469839 10495 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine" "node"="test-mhc-node-85bdh" E1115 03:35:23.469898 10495 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine" "node"="test-mhc-node-85bdh" E1115 03:35:23.470124 10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-85bdh, got []" "node"="test-mhc-node-85bdh" E1115 03:35:23.470159 10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-85bdh, got []" "node"="test-mhc-node-85bdh" inframachine created: test-mhc-machine-infra-qtknq machine created: test-mhc-machine-7t772 I1115 03:35:23.683207 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ptmvw" "namespace"="test-mhc-lgbtz" I1115 03:35:23.683664 10495 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-lgbtz/test-mhc-ptmvw/test-mhc-machine-7t772/" E1115 03:35:23.692328 10495 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine" "node"="test-mhc-node-9vxb5" node created: test-mhc-node-9vxb5 E1115 03:35:23.693011 10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-9vxb5, got []" "node"="test-mhc-node-9vxb5" I1115 03:35:23.696565 10495 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-7t772" "namespace"="test-mhc-lgbtz" "noderef"="test-mhc-node-9vxb5" I1115 03:35:23.721296 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ptmvw" "namespace"="test-mhc-lgbtz" I1115 03:35:23.882428 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ptmvw" "namespace"="test-mhc-lgbtz" I1115 03:35:23.884887 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ptmvw" "namespace"="test-mhc-lgbtz" Cleaning up nodes, machines and infra machines. I1115 03:35:23.894229 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ptmvw" "namespace"="test-mhc-lgbtz" I1115 03:35:23.894637 10495 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-lgbtz/test-mhc-ptmvw/test-mhc-machine-7k4tz/" I1115 03:35:23.912799 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ptmvw" "namespace"="test-mhc-lgbtz" I1115 03:35:23.913306 10495 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-lgbtz/test-mhc-ptmvw/test-mhc-machine-7k4tz/" I1115 03:35:23.913757 10495 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-lgbtz/test-mhc-ptmvw/test-mhc-machine-7t772/" E1115 03:35:23.960539 10495 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="test-mhc-lgbtz/test-cluster-2x6sv" === RUN TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine inframachine created: test-mhc-machine-infra-2fhkp E1115 03:35:24.112560 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"test-mhc-machine-7k4tz\" in namespace \"test-mhc-lgbtz\": cannot find node with matching ProviderID" "controller"="machine" "name"="test-mhc-machine-7k4tz" "namespace"="test-mhc-lgbtz" E1115 03:35:24.116502 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-ptmvw\" not found" "controller"="machinehealthcheck" "name"="test-mhc-ptmvw" "namespace"="test-mhc-lgbtz" machine created: test-mhc-machine-xkmfd E1115 03:35:24.122485 10495 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="test-machine-watches-45dld/machine-reconcile-9r7v5" E1115 03:35:25.112936 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7t772\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7t772" "namespace"="test-mhc-lgbtz" I1115 03:35:25.116777 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:25.173698 10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={} I1115 03:35:25.199259 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ptmvw" "namespace"="test-mhc-lgbtz" I1115 03:35:25.199338 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:25.215586 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:25.216606 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" ... skipping 412 lines ... I1115 03:35:26.103228 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:26.104927 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:26.106641 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:26.108406 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:26.110112 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:26.111802 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" E1115 03:35:26.113266 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7k4tz\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7k4tz" "namespace"="test-mhc-lgbtz" I1115 03:35:26.113439 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:26.115361 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:26.122471 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:26.124316 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:26.126058 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:26.127757 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" ... skipping 463 lines ... I1115 03:35:27.122135 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:27.123842 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:27.125769 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:27.126329 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:27.127451 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:27.129562 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" E1115 03:35:27.129739 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7t772\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7t772" "namespace"="test-mhc-lgbtz" I1115 03:35:27.130372 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:27.130636 10495 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-4rjqq/test-mhc-8xcrm/test-mhc-machine-xkmfd/" I1115 03:35:27.139960 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:27.140332 10495 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-4rjqq/test-mhc-8xcrm/test-mhc-machine-xkmfd/" E1115 03:35:27.230256 10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-tq5kj, got []" "node"="test-mhc-node-tq5kj" node created: test-mhc-node-tq5kj I1115 03:35:27.245886 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" inframachine created: test-mhc-machine-infra-9jtp8 I1115 03:35:27.267160 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" machine created: test-mhc-machine-6x6bk I1115 03:35:27.278664 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" ... skipping 289 lines ... I1115 03:35:28.115210 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:28.118049 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:28.121152 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:28.124111 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:28.127222 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:28.130006 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" E1115 03:35:28.131307 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7k4tz\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7k4tz" "namespace"="test-mhc-lgbtz" I1115 03:35:28.131959 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:28.134155 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:28.136392 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:28.138809 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:28.140940 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:28.143129 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" ... skipping 408 lines ... I1115 03:35:29.156244 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:29.172915 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:29.174465 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:29.175691 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:29.176755 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:29.185086 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" E1115 03:35:29.186429 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7t772\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7t772" "namespace"="test-mhc-lgbtz" I1115 03:35:29.189321 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:29.191452 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:29.192610 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:29.197459 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:29.207886 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:29.209698 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" ... skipping 353 lines ... I1115 03:35:30.189259 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:30.192964 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:30.195252 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:30.196278 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:30.198395 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:30.200673 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" E1115 03:35:30.201685 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7k4tz\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7k4tz" "namespace"="test-mhc-lgbtz" I1115 03:35:30.201749 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:30.202053 10495 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-4rjqq/test-mhc-8xcrm/test-mhc-machine-6x6bk/" I1115 03:35:30.211754 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:30.212204 10495 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-4rjqq/test-mhc-8xcrm/test-mhc-machine-6x6bk/" E1115 03:35:30.295077 10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-scvw9, got []" "node"="test-mhc-node-scvw9" node created: test-mhc-node-scvw9 I1115 03:35:30.302863 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" inframachine created: test-mhc-machine-infra-tbjvz machine created: test-mhc-machine-ch2cn I1115 03:35:30.319202 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:30.324852 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" ... skipping 260 lines ... I1115 03:35:31.196507 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:31.200142 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:31.210489 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:31.216028 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:31.219203 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:31.222927 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" E1115 03:35:31.224373 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7t772\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7t772" "namespace"="test-mhc-lgbtz" I1115 03:35:31.224474 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:31.227561 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:31.230302 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:31.233215 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:31.237926 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:31.241702 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" ... skipping 288 lines ... I1115 03:35:32.304183 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:32.306434 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:32.308685 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:32.319131 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:32.320804 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:32.322311 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" E1115 03:35:32.323616 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7k4tz\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7k4tz" "namespace"="test-mhc-lgbtz" I1115 03:35:32.326049 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:32.328705 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:32.331433 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:32.333926 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:32.336429 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:32.338988 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" ... skipping 247 lines ... I1115 03:35:33.338423 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:33.345305 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:33.347388 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:33.349431 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:33.351695 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:33.360948 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:33.361682 10495 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-4rjqq/test-mhc-8xcrm/test-mhc-machine-ch2cn/" E1115 03:35:33.363376 10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-74db8, got []" "node"="test-mhc-node-74db8" node created: test-mhc-node-74db8 E1115 03:35:33.376756 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7t772\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7t772" "namespace"="test-mhc-lgbtz" I1115 03:35:33.386443 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:33.387011 10495 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-4rjqq/test-mhc-8xcrm/test-mhc-machine-ch2cn/" Cleaning up nodes, machines and infra machines. I1115 03:35:33.391594 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:33.392133 10495 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-4rjqq/test-mhc-8xcrm/test-mhc-machine-ch2cn/test-mhc-node-74db8" I1115 03:35:33.402283 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8xcrm" "namespace"="test-mhc-4rjqq" I1115 03:35:33.402788 10495 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-4rjqq/test-mhc-8xcrm/test-mhc-machine-ch2cn/" Cleaning up nodes, machines and infra machines. I1115 03:35:33.453516 10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-rrpnm" "namespace"="test-mhc-4rjqq" "count"=2 I1115 03:35:33.453599 10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-rrpnm" "namespace"="test-mhc-4rjqq" "descendants"="Worker machines: test-mhc-machine-6x6bk,test-mhc-machine-ch2cn,test-mhc-machine-xkmfd" "indirect descendants count"=1 I1115 03:35:33.457586 10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-rrpnm" "namespace"="test-mhc-4rjqq" "count"=2 I1115 03:35:33.457646 10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-rrpnm" "namespace"="test-mhc-4rjqq" "descendants"="Worker machines: test-mhc-machine-ch2cn,test-mhc-machine-xkmfd,test-mhc-machine-6x6bk" "indirect descendants count"=1 === RUN TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy ... skipping 7 lines ... I1115 03:35:33.679051 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" I1115 03:35:33.720014 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" I1115 03:35:33.802297 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" I1115 03:35:33.963343 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" I1115 03:35:34.284439 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" I1115 03:35:34.377298 10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-rrpnm" "machine"="test-mhc-machine-6x6bk" "namespace"="test-mhc-4rjqq" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-scvw9"} E1115 03:35:34.418163 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-6x6bk\" not found" "controller"="machine" "name"="test-mhc-machine-6x6bk" "namespace"="test-mhc-4rjqq" I1115 03:35:34.926129 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" E1115 03:35:35.431474 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7k4tz\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7k4tz" "namespace"="test-mhc-lgbtz" I1115 03:35:36.211349 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" I1115 03:35:36.431961 10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-rrpnm" "machine"="test-mhc-machine-ch2cn" "namespace"="test-mhc-4rjqq" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-74db8"} E1115 03:35:36.483250 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-ch2cn\" not found" "controller"="machine" "name"="test-mhc-machine-ch2cn" "namespace"="test-mhc-4rjqq" I1115 03:35:37.483856 10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-rrpnm" "machine"="test-mhc-machine-xkmfd" "namespace"="test-mhc-4rjqq" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-tq5kj"} E1115 03:35:37.529285 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-xkmfd\" not found" "controller"="machine" "name"="test-mhc-machine-xkmfd" "namespace"="test-mhc-4rjqq" E1115 03:35:38.471920 10495 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="test-mhc-4rjqq/test-cluster-rrpnm" E1115 03:35:38.529677 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7t772\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7t772" "namespace"="test-mhc-lgbtz" I1115 03:35:38.772393 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" I1115 03:35:39.538260 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" I1115 03:35:39.545553 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" E1115 03:35:39.545981 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7k4tz\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7k4tz" "namespace"="test-mhc-lgbtz" node created: test-mhc-node-vrf7p E1115 03:35:39.559264 10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-vrf7p, got []" "node"="test-mhc-node-vrf7p" I1115 03:35:39.563469 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" I1115 03:35:39.567196 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" inframachine created: test-mhc-machine-infra-lr5vr machine created: test-mhc-machine-d5pxx I1115 03:35:39.612218 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" I1115 03:35:39.626372 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" I1115 03:35:39.627497 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" I1115 03:35:39.631478 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" I1115 03:35:39.672633 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" I1115 03:35:39.754052 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" I1115 03:35:39.915483 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" I1115 03:35:40.236893 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" E1115 03:35:40.546580 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7t772\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7t772" "namespace"="test-mhc-lgbtz" I1115 03:35:40.879988 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" I1115 03:35:41.569985 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" I1115 03:35:41.578039 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" I1115 03:35:41.591888 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" I1115 03:35:41.599030 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" I1115 03:35:41.615346 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" E1115 03:35:41.617239 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7k4tz\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7k4tz" "namespace"="test-mhc-lgbtz" I1115 03:35:41.618207 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" I1115 03:35:41.646595 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" E1115 03:35:41.707229 10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-lw8k7, got []" "node"="test-mhc-node-lw8k7" node created: test-mhc-node-lw8k7 I1115 03:35:41.715791 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" inframachine created: test-mhc-machine-infra-rq6p6 I1115 03:35:41.733813 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" I1115 03:35:41.747014 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" machine created: test-mhc-machine-wf9dd I1115 03:35:41.773369 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" I1115 03:35:42.161319 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" E1115 03:35:42.617648 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7t772\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7t772" "namespace"="test-mhc-lgbtz" I1115 03:35:43.629330 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" I1115 03:35:43.643475 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" I1115 03:35:43.650112 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" I1115 03:35:43.669218 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" I1115 03:35:43.676116 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" I1115 03:35:43.691353 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" I1115 03:35:43.697658 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" E1115 03:35:43.699853 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7k4tz\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7k4tz" "namespace"="test-mhc-lgbtz" I1115 03:35:43.721520 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" E1115 03:35:43.773234 10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-pgs6t, got []" "node"="test-mhc-node-pgs6t" node created: test-mhc-node-pgs6t I1115 03:35:43.780018 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" Cleaning up nodes, machines and infra machines. I1115 03:35:43.793855 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h8k98" "namespace"="test-mhc-rj454" Cleaning up nodes, machines and infra machines. I1115 03:35:43.832546 10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-wgntj" "namespace"="test-mhc-rj454" "count"=2 ... skipping 5 lines ... I1115 03:35:43.963962 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" inframachine created: test-mhc-machine-infra-p7bpv I1115 03:35:43.998927 10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={} machine created: test-mhc-machine-57q5f I1115 03:35:44.016378 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" I1115 03:35:44.021997 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" E1115 03:35:44.700305 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7t772\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7t772" "namespace"="test-mhc-lgbtz" I1115 03:35:45.700857 10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-wgntj" "machine"="test-mhc-machine-kqxwz" "namespace"="test-mhc-rj454" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-vrf7p"} E1115 03:35:45.751842 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-kqxwz\" not found" "controller"="machine" "name"="test-mhc-machine-kqxwz" "namespace"="test-mhc-rj454" I1115 03:35:46.752400 10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-wgntj" "machine"="test-mhc-machine-d5pxx" "namespace"="test-mhc-rj454" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-lw8k7"} E1115 03:35:46.790151 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-d5pxx\" not found" "controller"="machine" "name"="test-mhc-machine-d5pxx" "namespace"="test-mhc-rj454" I1115 03:35:47.790630 10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-wgntj" "machine"="test-mhc-machine-wf9dd" "namespace"="test-mhc-rj454" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-pgs6t"} E1115 03:35:47.835476 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-wf9dd\" not found" "controller"="machine" "name"="test-mhc-machine-wf9dd" "namespace"="test-mhc-rj454" I1115 03:35:48.846898 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" E1115 03:35:48.853076 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7k4tz\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7k4tz" "namespace"="test-mhc-lgbtz" I1115 03:35:48.853108 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" E1115 03:35:48.853582 10495 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="test-mhc-rj454/test-cluster-wgntj" E1115 03:35:48.936727 10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8nclh, got []" "node"="test-mhc-node-8nclh" node created: test-mhc-node-8nclh I1115 03:35:48.945168 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" inframachine created: test-mhc-machine-infra-77wxq I1115 03:35:48.961410 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" I1115 03:35:48.962926 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" machine created: test-mhc-machine-n7djs I1115 03:35:48.974138 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" E1115 03:35:49.853440 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7t772\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7t772" "namespace"="test-mhc-lgbtz" I1115 03:35:50.866606 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" I1115 03:35:50.874152 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" I1115 03:35:50.882029 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" I1115 03:35:50.888482 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" I1115 03:35:50.897595 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" I1115 03:35:50.904172 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" I1115 03:35:50.921215 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" I1115 03:35:50.937473 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" I1115 03:35:50.947246 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" I1115 03:35:50.963643 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" node created: test-mhc-node-d82k4 E1115 03:35:50.976405 10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-d82k4, got []" "node"="test-mhc-node-d82k4" I1115 03:35:50.980600 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" I1115 03:35:50.987892 10495 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-n7djs" "namespace"="test-mhc-r94v9" "noderef"="test-mhc-node-d82k4" I1115 03:35:50.989123 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" inframachine created: test-mhc-machine-infra-pc2dq machine created: test-mhc-machine-rwvbc I1115 03:35:51.017536 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" ... skipping 9 lines ... I1115 03:35:51.238755 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" I1115 03:35:51.249948 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" I1115 03:35:51.252218 10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-j8r6d" "machine"="test-mhc-machine-rwvbc" "namespace"="test-mhc-r94v9" "cause"="noderef is nil" "node"=null Cleaning up nodes, machines and infra machines. I1115 03:35:51.260159 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" I1115 03:35:51.262482 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" I1115 03:35:51.263028 10495 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-r94v9/test-mhc-cwt4t/test-mhc-machine-57q5f/" I1115 03:35:51.293307 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" I1115 03:35:51.294017 10495 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-r94v9/test-mhc-cwt4t/test-mhc-machine-57q5f/" I1115 03:35:51.294488 10495 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-r94v9/test-mhc-cwt4t/test-mhc-machine-n7djs/" E1115 03:35:51.338118 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-rwvbc\" not found" "controller"="machine" "name"="test-mhc-machine-rwvbc" "namespace"="test-mhc-r94v9" I1115 03:35:51.346855 10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-j8r6d" "namespace"="test-mhc-r94v9" "count"=2 I1115 03:35:51.346938 10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-j8r6d" "namespace"="test-mhc-r94v9" "descendants"="Worker machines: test-mhc-machine-57q5f,test-mhc-machine-n7djs" "indirect descendants count"=0 I1115 03:35:51.350817 10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-j8r6d" "namespace"="test-mhc-r94v9" "count"=2 I1115 03:35:51.350896 10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-j8r6d" "namespace"="test-mhc-r94v9" "descendants"="Worker machines: test-mhc-machine-57q5f,test-mhc-machine-n7djs" "indirect descendants count"=0 === RUN TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_longer_than_the_NodeStartupTimeout === RUN TestMachineHealthCheck_Reconcile/when_a_Machine's_Node_has_gone_away === RUN TestMachineHealthCheck_Reconcile/should_react_when_a_Node_transitions_to_unhealthy inframachine created: test-mhc-machine-infra-r6css machine created: test-mhc-machine-ktk5b E1115 03:35:51.474522 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-cwt4t\" not found" "controller"="machinehealthcheck" "name"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" I1115 03:35:52.338696 10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-j8r6d" "machine"="test-mhc-machine-57q5f" "namespace"="test-mhc-r94v9" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-8nclh"} E1115 03:35:52.386759 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-57q5f\" not found" "controller"="machine" "name"="test-mhc-machine-57q5f" "namespace"="test-mhc-r94v9" I1115 03:35:52.474842 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" I1115 03:35:52.497057 10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={} I1115 03:35:52.614251 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cwt4t" "namespace"="test-mhc-r94v9" I1115 03:35:52.614320 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" I1115 03:35:52.614956 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" I1115 03:35:52.615548 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" ... skipping 388 lines ... I1115 03:35:53.439999 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" I1115 03:35:53.441939 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" I1115 03:35:53.443904 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" I1115 03:35:53.445858 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" I1115 03:35:53.448099 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" I1115 03:35:53.450099 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" E1115 03:35:53.451509 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-n7djs\" not found" "controller"="machine" "name"="test-mhc-machine-n7djs" "namespace"="test-mhc-r94v9" I1115 03:35:53.452229 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" I1115 03:35:53.456638 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" I1115 03:35:53.458349 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" I1115 03:35:53.460039 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" I1115 03:35:53.461804 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" I1115 03:35:53.463533 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" ... skipping 476 lines ... I1115 03:35:54.457341 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" I1115 03:35:54.458872 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" I1115 03:35:54.460260 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" I1115 03:35:54.460794 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" I1115 03:35:54.462437 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" I1115 03:35:54.464258 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" I1115 03:35:54.464547 10495 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-kf227/test-mhc-9tb7q/test-mhc-machine-ktk5b/" E1115 03:35:54.464804 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7k4tz\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7k4tz" "namespace"="test-mhc-lgbtz" I1115 03:35:54.474048 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" I1115 03:35:54.474305 10495 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-kf227/test-mhc-9tb7q/test-mhc-machine-ktk5b/" node created: test-mhc-node-rxv4l E1115 03:35:54.512720 10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-rxv4l, got []" "node"="test-mhc-node-rxv4l" E1115 03:35:54.512947 10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-rxv4l, got []" "node"="test-mhc-node-rxv4l" I1115 03:35:54.523538 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" I1115 03:35:54.537334 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" I1115 03:35:54.538255 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" I1115 03:35:54.548186 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" I1115 03:35:54.549655 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" I1115 03:35:54.549942 10495 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-kf227/test-mhc-9tb7q/test-mhc-machine-ktk5b/test-mhc-node-rxv4l" I1115 03:35:54.562557 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" I1115 03:35:54.562940 10495 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-kf227/test-mhc-9tb7q/test-mhc-machine-ktk5b/test-mhc-node-rxv4l" I1115 03:35:54.563561 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" I1115 03:35:54.563828 10495 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-kf227/test-mhc-9tb7q/test-mhc-machine-ktk5b/test-mhc-node-rxv4l" Cleaning up nodes, machines and infra machines. I1115 03:35:54.573994 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" I1115 03:35:54.574331 10495 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-kf227/test-mhc-9tb7q/test-mhc-machine-ktk5b/test-mhc-node-rxv4l" I1115 03:35:54.575004 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" I1115 03:35:54.576243 10495 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="NodeNotFound" "target"="test-mhc-kf227/test-mhc-9tb7q/test-mhc-machine-ktk5b/" I1115 03:35:54.591478 10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-2fdr2" "namespace"="test-mhc-kf227" "descendants"="Worker machines: test-mhc-machine-ktk5b" "indirect descendants count"=1 I1115 03:35:54.595997 10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-2fdr2" "namespace"="test-mhc-kf227" "descendants"="Worker machines: test-mhc-machine-ktk5b" "indirect descendants count"=1 === RUN TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted I1115 03:35:54.727425 10495 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-62njv" "namespace"="test-mhc-nfjsn" "creating"=1 "need"=1 I1115 03:35:54.727479 10495 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-62njv" "namespace"="test-mhc-nfjsn" I1115 03:35:54.756248 10495 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-62njv-n8jfm\"" "machineset"="mhc-ms-62njv" "namespace"="test-mhc-nfjsn" I1115 03:35:54.758367 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9tb7q" "namespace"="test-mhc-kf227" I1115 03:35:54.816086 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9bw5k" "namespace"="test-mhc-nfjsn" I1115 03:35:54.830400 10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={} I1115 03:35:54.850834 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9bw5k" "namespace"="test-mhc-nfjsn" E1115 03:35:55.465319 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7t772\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7t772" "namespace"="test-mhc-lgbtz" I1115 03:35:55.851059 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9bw5k" "namespace"="test-mhc-nfjsn" E1115 03:35:56.364796 10495 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="test-mhc-r94v9/test-cluster-j8r6d" I1115 03:35:56.465889 10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-2fdr2" "machine"="test-mhc-machine-ktk5b" "namespace"="test-mhc-kf227" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-rxv4l"} E1115 03:35:56.516499 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-ktk5b\" not found" "controller"="machine" "name"="test-mhc-machine-ktk5b" "namespace"="test-mhc-kf227" I1115 03:35:56.852054 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9bw5k" "namespace"="test-mhc-nfjsn" I1115 03:35:57.525205 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9bw5k" "namespace"="test-mhc-nfjsn" I1115 03:35:57.525352 10495 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-62njv" "namespace"="test-mhc-nfjsn" I1115 03:35:57.530479 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9bw5k" "namespace"="test-mhc-nfjsn" I1115 03:35:57.531279 10495 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-62njv" "namespace"="test-mhc-nfjsn" I1115 03:35:57.549415 10495 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-62njv-n8jfm" "namespace"="test-mhc-nfjsn" ... skipping 7 lines ... I1115 03:35:57.579391 10495 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-62njv-n8jfm" "namespace"="test-mhc-nfjsn" I1115 03:35:57.579439 10495 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-62njv-n8jfm" "namespace"="test-mhc-nfjsn" I1115 03:35:57.852829 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9bw5k" "namespace"="test-mhc-nfjsn" I1115 03:35:58.565900 10495 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-62njv-n8jfm" "namespace"="test-mhc-nfjsn" I1115 03:35:58.565955 10495 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-62njv-n8jfm" "namespace"="test-mhc-nfjsn" I1115 03:35:59.000790 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9bw5k" "namespace"="test-mhc-nfjsn" I1115 03:35:59.001254 10495 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-nfjsn/test-mhc-9bw5k/mhc-ms-62njv-n8jfm/" I1115 03:35:59.009866 10495 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-62njv" "namespace"="test-mhc-nfjsn" I1115 03:35:59.013961 10495 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-62njv-n8jfm" "namespace"="test-mhc-nfjsn" I1115 03:35:59.014009 10495 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-62njv-n8jfm" "namespace"="test-mhc-nfjsn" I1115 03:35:59.014089 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9bw5k" "namespace"="test-mhc-nfjsn" I1115 03:35:59.014387 10495 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-nfjsn/test-mhc-9bw5k/mhc-ms-62njv-n8jfm/" I1115 03:35:59.025283 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9bw5k" "namespace"="test-mhc-nfjsn" I1115 03:35:59.025341 10495 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-62njv" "namespace"="test-mhc-nfjsn" I1115 03:35:59.025644 10495 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-nfjsn/test-mhc-9bw5k/mhc-ms-62njv-n8jfm/" I1115 03:35:59.051238 10495 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-62njv-n8jfm" "namespace"="test-mhc-nfjsn" I1115 03:35:59.051280 10495 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-62njv-n8jfm" "namespace"="test-mhc-nfjsn" I1115 03:35:59.071438 10495 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-62njv" "namespace"="test-mhc-nfjsn" "machine"="mhc-ms-62njv-n8jfm" I1115 03:35:59.077262 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9bw5k" "namespace"="test-mhc-nfjsn" I1115 03:35:59.078373 10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-48vfh" "machine"="mhc-ms-62njv-n8jfm" "namespace"="test-mhc-nfjsn" "cause"="noderef is nil" "node"=null I1115 03:35:59.080144 10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-48vfh" "namespace"="test-mhc-nfjsn" "count"=1 I1115 03:35:59.080206 10495 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-48vfh" "namespace"="test-mhc-nfjsn" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-62njv" I1115 03:35:59.080291 10495 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-nfjsn/test-mhc-9bw5k/mhc-ms-62njv-n8jfm/" I1115 03:35:59.087025 10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-48vfh" "namespace"="test-mhc-nfjsn" "descendants"="Machine sets: mhc-ms-62njv;Worker machines: mhc-ms-62njv-n8jfm" "indirect descendants count"=1 I1115 03:35:59.092265 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9bw5k" "namespace"="test-mhc-nfjsn" I1115 03:35:59.092585 10495 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-nfjsn/test-mhc-9bw5k/mhc-ms-62njv-n8jfm/" I1115 03:35:59.102403 10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-48vfh" "namespace"="test-mhc-nfjsn" "descendants"="Worker machines: mhc-ms-62njv-n8jfm" "indirect descendants count"=1 === RUN TestMachineHealthCheck_Reconcile/when_a_machine_is_paused === RUN TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created I1115 03:35:59.127410 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9bw5k" "namespace"="test-mhc-nfjsn" I1115 03:35:59.314966 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" inframachine created: test-mhc-machine-infra-sxhf9 I1115 03:35:59.329893 10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-48vfh" "machine"="mhc-ms-62njv-n8jfm" "namespace"="test-mhc-nfjsn" "cause"="cluster is being deleted" "node"=null I1115 03:35:59.347965 10495 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={} machine created: test-mhc-machine-t2hqd E1115 03:35:59.374937 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-62njv-n8jfm\" not found" "controller"="machine" "name"="mhc-ms-62njv-n8jfm" "namespace"="test-mhc-nfjsn" I1115 03:35:59.466803 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" I1115 03:35:59.467553 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" I1115 03:35:59.468176 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" I1115 03:35:59.471955 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" I1115 03:35:59.473708 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" I1115 03:35:59.475818 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" ... skipping 48 lines ... I1115 03:35:59.598393 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" I1115 03:35:59.600126 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" I1115 03:35:59.602988 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" I1115 03:35:59.604678 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" I1115 03:35:59.606453 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" I1115 03:35:59.608172 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" E1115 03:35:59.608655 10495 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="test-mhc-kf227/test-cluster-2fdr2" I1115 03:35:59.609869 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" I1115 03:35:59.611601 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" I1115 03:35:59.613323 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" I1115 03:35:59.615016 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" I1115 03:35:59.618329 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" I1115 03:35:59.620052 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" ... skipping 323 lines ... I1115 03:36:00.381198 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" I1115 03:36:00.383027 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" I1115 03:36:00.383958 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" I1115 03:36:00.385986 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" I1115 03:36:00.387880 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" I1115 03:36:00.388524 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" E1115 03:36:00.388860 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7k4tz\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7k4tz" "namespace"="test-mhc-lgbtz" I1115 03:36:00.452489 10495 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-t2hqd" "target"="test-mhc-69tm4/test-mhc-hdz4v/test-mhc-machine-t2hqd/" E1115 03:36:00.466765 10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-4tqxf, got []" "node"="test-mhc-node-4tqxf" E1115 03:36:00.466996 10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-4tqxf, got []" "node"="test-mhc-node-4tqxf" node created: test-mhc-node-4tqxf I1115 03:36:00.471543 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" I1115 03:36:00.476272 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" I1115 03:36:00.499901 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" I1115 03:36:00.508624 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" I1115 03:36:00.510827 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" I1115 03:36:00.514147 10495 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-t2hqd" "target"="test-mhc-69tm4/test-mhc-hdz4v/test-mhc-machine-t2hqd/test-mhc-node-4tqxf" I1115 03:36:00.536478 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" Cleaning up nodes, machines and infra machines. I1115 03:36:00.544717 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" I1115 03:36:00.547352 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" I1115 03:36:00.551531 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hdz4v" "namespace"="test-mhc-69tm4" I1115 03:36:00.558197 10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-smrql" "namespace"="test-mhc-69tm4" "descendants"="Worker machines: test-mhc-machine-t2hqd" "indirect descendants count"=1 ... skipping 332 lines ... I1115 03:36:01.448560 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:01.450576 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:01.452863 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:01.454652 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:01.456803 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:01.458596 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" E1115 03:36:01.460259 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-t2hqd\" not found" "controller"="machine" "name"="test-mhc-machine-t2hqd" "namespace"="test-mhc-69tm4" I1115 03:36:01.460403 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:01.462190 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:01.463965 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:01.465711 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:01.467548 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:01.469333 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" ... skipping 535 lines ... I1115 03:36:02.451336 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:02.453218 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:02.455101 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:02.456842 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:02.458446 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:02.460126 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" E1115 03:36:02.460610 10495 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-2x6sv\" for machine \"test-mhc-machine-7t772\" in namespace \"test-mhc-lgbtz\": Cluster.cluster.x-k8s.io \"test-cluster-2x6sv\" not found" "controller"="machine" "name"="test-mhc-machine-7t772" "namespace"="test-mhc-lgbtz" I1115 03:36:02.462019 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:02.463668 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:02.465280 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:02.466942 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:02.468734 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:02.470459 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" ... skipping 562 lines ... I1115 03:36:03.463672 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:03.465206 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:03.467358 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:03.468025 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:03.469112 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:03.470841 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:03.478069 10495 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-lgtt8" "target"="test-mhc-ktqg6/test-mhc-6r8z4/test-mhc-machine-lgtt8/" I1115 03:36:03.487932 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" E1115 03:36:03.536658 10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-snffj, got []" "node"="test-mhc-node-snffj" node created: test-mhc-node-snffj E1115 03:36:03.536824 10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-snffj, got []" "node"="test-mhc-node-snffj" E1115 03:36:03.536860 10495 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-snffj, got []" "node"="test-mhc-node-snffj" I1115 03:36:03.543266 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:03.560495 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:03.569046 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:03.572251 10495 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-lgtt8" "target"="test-mhc-ktqg6/test-mhc-6r8z4/test-mhc-machine-lgtt8/test-mhc-node-snffj" I1115 03:36:03.589145 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:03.600242 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:03.824641 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:03.828059 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" Cleaning up nodes, machines and infra machines. I1115 03:36:03.838705 10495 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6r8z4" "namespace"="test-mhc-ktqg6" I1115 03:36:03.841491 10495 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-lgtt8" "target"="test-mhc-ktqg6/test-mhc-6r8z4/test-mhc-machine-lgtt8/" I1115 03:36:03.843052 10495 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-6n5gv" "machine"="test-mhc-machine-lgtt8" "namespace"="test-mhc-ktqg6" "cause"="no control plane members" "node"={"name":"test-mhc-node-snffj"} I1115 03:36:03.853048 10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-6n5gv" "namespace"="test-mhc-ktqg6" "count"=1 I1115 03:36:03.853110 10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-6n5gv" "namespace"="test-mhc-ktqg6" "descendants"="Worker machines: test-mhc-machine-lgtt8" "indirect descendants count"=0 I1115 03:36:03.856260 10495 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-6n5gv" "namespace"="test-mhc-ktqg6" "count"=1 I1115 03:36:03.856385 10495 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-6n5gv" "namespace"="test-mhc-ktqg6" "descendants"="Worker machines: test-mhc-machine-lgtt8" "indirect descendants count"=0 --- PASS: TestMachineHealthCheck_Reconcile (42.07s) ... skipping 15 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.46s) --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (3.29s) === RUN TestClusterToMachineHealthCheck === RUN TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster E1115 03:36:03.863132 10495 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 E1115 03:36:03.864432 10495 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 E1115 03:36:03.866007 10495 machinehealthcheck_controller.go:474] "msg"="expected a Node" "error"="incorrect type" "type"="handler.MapObject" === RUN TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node E1115 03:36:03.866252 10495 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 E1115 03:36:03.866618 10495 machinehealthcheck_controller.go:480] "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node node1, got [machine1 machine2]" "node"="node1" === RUN TestNodeToMachineHealthCheck/when_no_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace === RUN TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace === RUN TestNodeToMachineHealthCheck/when_two_MachineHealthChecks_exist_for_the_Node_in_the_Machine's_namespace === RUN TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node,_but_not_in_the_Machine's_cluster --- PASS: TestNodeToMachineHealthCheck (0.00s) --- PASS: TestNodeToMachineHealthCheck/when_the_object_passed_isn't_a_Node (0.00s) ... skipping 31 lines ... --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_nil (0.00s) --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_not_an_int_or_percentage (0.00s) --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_an_int (0.00s) --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_a_40%_(of_5) (0.00s) --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_a_60%_(of_7) (0.00s) === RUN TestPatchTargets I1115 03:36:03.871655 10495 machinehealthcheck_controller.go:387] "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="" "target"="default/mhc/machine1/" I1115 03:36:03.872534 10495 machinehealthcheck_controller.go:387] "msg"="Target has failed health check, marking for remediation" "message"="" "reason"="" "target"="default/mhc/machine2/" E1115 03:36:03.875006 10495 machinehealthcheck_controller.go:320] "msg"="failed to patch healthy machine status for machine" "error"="machines.cluster.x-k8s.io \"machine1\" not found" "machine"="machine1" --- PASS: TestPatchTargets (0.01s) === RUN TestGetTargetsFromMHC === RUN TestGetTargetsFromMHC/with_no_matching_machines === RUN TestGetTargetsFromMHC/when_a_machine's_node_is_missing === RUN TestGetTargetsFromMHC/when_a_machine's_labels_do_not_match_the_selector fatal error: concurrent map read and map write goroutine 1168 [running]: runtime.throw(0x19d1121, 0x21) /usr/local/go/src/runtime/panic.go:774 +0x72 fp=0xc0011cae58 sp=0xc0011cae28 pc=0x4314c2 runtime.mapaccess2(0x177f3a0, 0xc000281650, 0xc0011caf18, 0x203000, 0x203000) /usr/local/go/src/runtime/map.go:470 +0x278 fp=0xc0011caea0 sp=0xc0011cae58 pc=0x40fda8 ... skipping 4 lines ... k8s.io/apimachinery/pkg/runtime/serializer/json.(*Serializer).Decode(0xc00013d400, 0xc000ada000, 0x108, 0x200, 0xc000c7b500, 0x0, 0x0, 0x40df46, 0xc000c7b500, 0x30, ...) /home/prow/go/pkg/mod/k8s.io/apimachinery@v0.17.9/pkg/runtime/serializer/json/json.go:258 +0x57a fp=0xc0011cb3c0 sp=0xc0011cb098 pc=0xa049aa k8s.io/apimachinery/pkg/runtime.WithoutVersionDecoder.Decode(0x1c211a0, 0xc00013d400, 0xc000ada000, 0x108, 0x200, 0xc000c7b500, 0x0, 0x0, 0x40e7b8, 0x30, ...) /home/prow/go/pkg/mod/k8s.io/apimachinery@v0.17.9/pkg/runtime/helper.go:252 +0x97 fp=0xc0011cb458 sp=0xc0011cb3c0 pc=0x87ef67 k8s.io/apimachinery/pkg/runtime.(*WithoutVersionDecoder).Decode(0xc000ff6d60, 0xc000ada000, 0x108, 0x200, 0xc000c7b500, 0x0, 0x0, 0xc000c78a80, 0xc000c78980, 0xc000c54000, ...) <autogenerated>:1 +0x9f fp=0xc0011cb4d0 sp=0xc0011cb458 pc=0x88ad3f k8s.io/client-go/rest.Result.Error(0xc000ada000, 0x108, 0x200, 0xc000f10440, 0x10, 0x1c21000, 0xc0000eeaa0, 0x194, 0x1c227c0, 0xc000ff6d60, ...) /home/prow/go/pkg/mod/k8s.io/client-go@v0.17.9/rest/request.go:1218 +0x11a fp=0xc0011cb560 sp=0xc0011cb4d0 pc=0xa2dfaa k8s.io/client-go/rest.Result.Into(0xc000ada000, 0x108, 0x200, 0xc000f10440, 0x10, 0x1c21000, 0xc0000eeaa0, 0x194, 0x1c227c0, 0xc000ff6d60, ...) /home/prow/go/pkg/mod/k8s.io/client-go@v0.17.9/rest/request.go:1172 +0x3b3 fp=0xc0011cb628 sp=0xc0011cb560 pc=0xa2dde3 sigs.k8s.io/controller-runtime/pkg/client.(*typedClient).PatchStatus(0xc00013d5e0, 0x1c61e80, 0xc0000d6010, 0x1c311a0, 0xc000e6a280, 0x1c31820, 0xc000c2a680, 0x0, 0x0, 0x0, ...) /home/prow/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.5.14/pkg/client/typed_client.go:209 +0x48e fp=0xc0011cb760 sp=0xc0011cb628 pc=0x120074e sigs.k8s.io/controller-runtime/pkg/client.(*statusWriter).Patch(0xc00013e0d0, 0x1c61e80, 0xc0000d6010, 0x1c311a0, 0xc000e6a280, 0x1c31820, 0xc000c2a680, 0x0, 0x0, 0x0, ...) ... skipping 2915 lines ... k8s.io/client-go/tools/cache.(*controller).Run(0xc0009f0300, 0xc000b62120) /home/prow/go/pkg/mod/k8s.io/client-go@v0.17.9/tools/cache/controller.go:125 +0x2fd k8s.io/client-go/tools/cache.(*sharedIndexInformer).Run(0xc000136360, 0xc000b62120) /home/prow/go/pkg/mod/k8s.io/client-go@v0.17.9/tools/cache/shared_informer.go:331 +0x47f created by sigs.k8s.io/controller-runtime/pkg/cache/internal.(*specificInformersMap).Start.func1 /home/prow/go/pkg/mod/sigs.k8s.io/controller-runtime@v0.5.14/pkg/cache/internal/informers_map.go:137 +0x122 FAIL sigs.k8s.io/cluster-api/controllers 58.915s === RUN TestGetResourceFound --- PASS: TestGetResourceFound (0.00s) === RUN TestGetResourceNotFound --- PASS: TestGetResourceNotFound (0.00s) === RUN TestCloneTemplateResourceNotFound --- PASS: TestCloneTemplateResourceNotFound (0.00s) ... skipping 255 lines ... I1115 03:35:18.547373 10837 webhook.go:123] controller-runtime/builder "msg"="Registering a validating webhook" "GVK"={"Group":"addons.cluster.x-k8s.io","Version":"v1alpha3","Kind":"ClusterResourceSet"} "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset" I1115 03:35:18.547399 10837 server.go:121] controller-runtime/webhook "msg"="registering webhook" "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset" I1115 03:35:18.547599 10837 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server" I1115 03:35:18.548775 10837 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate" I1115 03:35:18.548997 10837 server.go:199] controller-runtime/webhook "msg"="serving webhook server" "host"="" "port"=33551 I1115 03:35:18.549221 10837 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher" E1115 03:35:20.758263 10837 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="timed out waiting for the condition" "cluster"="cluster-cache-test-5l8vd/test-cluster" [32m•[0mE1115 03:35:21.213188 10837 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="the server could not find the requested resource" "cluster"="cluster-cache-test-drqtr/test-cluster" [32m•[0mE1115 03:35:21.783290 10837 cluster_cache.go:366] "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:39659/?timeout=50ms: dial tcp 127.0.0.1:39659: connect: connection refused" "cluster"="cluster-cache-test-l9jvc/test-cluster" [32m•[0mI1115 03:35:22.018638 10837 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="cluster" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}} I1115 03:35:22.118995 10837 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="cluster" I1115 03:35:22.119066 10837 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1 [32m•[0mI1115 03:35:22.319692 10837 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" I1115 03:35:22.346031 10837 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":{}}} I1115 03:35:22.646457 10837 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" I1115 03:35:22.646523 10837 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1 I1115 03:35:22.646618 10837 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={} [32m•[0mI1115 03:35:23.170171 10837 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" E1115 03:35:23.170341 10837 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory" E1115 03:35:23.170393 10837 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-149011369/tls.crt: no such file or directory" I1115 03:35:23.170397 10837 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server" E1115 03:35:23.219813 10837 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:44683/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=146&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:44683: connect: connection refused [1m[32mRan 5 of 5 Specs in 16.958 seconds[0m [1m[32mSUCCESS![0m -- [32m[1m5 Passed[0m | [91m[1m0 Failed[0m | [33m[1m0 Pending[0m | [36m[1m0 Skipped[0m --- PASS: TestGinkgoSuite (16.96s) PASS ok sigs.k8s.io/cluster-api/controllers/remote 17.119s ? 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 I1115 03:35:32.287212 11586 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 E1115 03:35:32.288452 11586 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 I1115 03:35:32.289075 11586 controller.go:136] "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" I1115 03:35:32.289259 11586 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 I1115 03:35:48.702532 11586 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 I1115 03:35:48.702782 11586 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: [1m1668483317[0m Will run [1m1[0m of [1m1[0m specs E1115 03:35:48.724637 11586 controller.go:126] "msg"="Failed to retrieve owner Cluster from the API Server" "error"="Cluster.cluster.x-k8s.io \"kcp-foo-9jd96s\" not found" "kubeadmControlPlane"="kcp-foo-9jd96s" "namespace"="test" [32m•[0m [1m[32mRan 1 of 1 Specs in 0.018 seconds[0m [1m[32mSUCCESS![0m -- [32m[1m1 Passed[0m | [91m[1m0 Failed[0m | [33m[1m0 Pending[0m | [36m[1m0 Skipped[0m --- PASS: TestAPIs (0.02s) === RUN TestKubeadmControlPlaneReconciler_upgradeControlPlane I1115 03:35:48.726002 11586 controller.go:246] "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-r51bxl" "kubeadmControlPlane"="kcp-foo-r51bxl" "namespace"="test" I1115 03:35:50.440750 11586 controller.go:331] "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-r51bxl" "kubeadmControlPlane"="kcp-foo-r51bxl" "namespace"="test" "needRollout"=["kcp-foo-r51bxl-vsbpj"] I1115 03:35:50.440921 11586 scale.go:212] "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-r51bxl" "kubeadmControlPlane"="kcp-foo-r51bxl" "namespace"="test" "failures"="[machine kcp-foo-r51bxl-8f6gg does not have APIServerPodHealthy condition, machine kcp-foo-r51bxl-8f6gg does not have ControllerManagerPodHealthy condition, machine kcp-foo-r51bxl-8f6gg does not have SchedulerPodHealthy condition, machine kcp-foo-r51bxl-8f6gg does not have EtcdPodHealthy condition, machine kcp-foo-r51bxl-8f6gg does not have EtcdMemberHealthy condition]" --- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (1.72s) ... skipping 60 lines ... ================================== Random Seed: [1m1668483316[0m Will run [1m7[0m of [1m7[0m specs [32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0m [1m[32mRan 7 of 7 Specs in 0.000 seconds[0m [1m[32mSUCCESS![0m -- [32m[1m7 Passed[0m | [91m[1m0 Failed[0m | [33m[1m0 Pending[0m | [36m[1m0 Skipped[0m --- PASS: TestControlPlane (0.00s) === RUN TestHasUnhealthyMachine --- PASS: TestHasUnhealthyMachine (0.00s) === RUN TestNewFailureDomainPicker === RUN TestNewFailureDomainPicker/simple === RUN TestNewFailureDomainPicker/no_machines ... skipping 111 lines ... ======================================= Random Seed: [1m1668483316[0m Will run [1m7[0m of [1m7[0m specs [32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0m [1m[32mRan 7 of 7 Specs in 0.001 seconds[0m [1m[32mSUCCESS![0m -- [32m[1m7 Passed[0m | [91m[1m0 Failed[0m | [33m[1m0 Pending[0m | [36m[1m0 Skipped[0m --- PASS: TestMachineCollection (0.00s) === RUN TestUpdateEtcdConditions === RUN TestUpdateEtcdConditions/if_list_nodes_return_an_error_should_report_all_the_conditions_Unknown === RUN TestUpdateEtcdConditions/node_without_machine_should_be_ignored_if_there_are_provisioning_machines === RUN TestUpdateEtcdConditions/node_without_machine_should_report_a_problem_at_KCP_level_if_there_are_no_provisioning_machines === RUN TestUpdateEtcdConditions/failure_creating_the_etcd_client_should_report_unknown_condition ... skipping 297 lines ... --- PASS: TestUpdateKubeProxyImageInfo/returns_error_if_image_repository_is_invalid (0.00s) --- PASS: TestUpdateKubeProxyImageInfo/does_not_update_image_repository_when_no_kube-proxy_update_is_requested (0.00s) === RUN TestRemoveMachineFromKubeadmConfigMap === RUN TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil === RUN TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil === RUN TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_find_kubeadm-config_for_Kubernetes_version_<_1.22.0 E1115 03:35:31.622973 11541 workload_cluster.go:354] "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found" E1115 03:35:39.946458 11541 workload_cluster.go:354] "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found" E1115 03:35:48.932720 11541 workload_cluster.go:354] "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found" E1115 03:36:00.062999 11541 workload_cluster.go:354] "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found" E1115 03:36:16.536223 11541 workload_cluster.go:354] "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found" E1115 03:36:29.544773 11541 workload_cluster.go:354] "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found" E1115 03:36:47.192149 11541 workload_cluster.go:354] "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found" E1115 03:37:08.115600 11541 workload_cluster.go:354] "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found" E1115 03:37:39.132082 11541 workload_cluster.go:354] "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found" E1115 03:38:24.289291 11541 workload_cluster.go:354] "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found" === RUN TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_remove_api_endpoint_for_Kubernetes_version_<_1.22.0 === RUN TestRemoveMachineFromKubeadmConfigMap/removes_the_machine_node_ref_from_kubeadm_config_for_Kubernetes_version_<_1.22.0 === RUN TestRemoveMachineFromKubeadmConfigMap/no_op_for_Kubernetes_version_>=_1.22.0 --- PASS: TestRemoveMachineFromKubeadmConfigMap (172.67s) --- PASS: TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil (0.00s) --- PASS: TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil (0.00s) ... skipping 83 lines ... --- PASS: TestIsKubernetesVersionSupported/workload_cluster_and_version_<_v1.22.0 (0.00s) --- PASS: TestIsKubernetesVersionSupported/workload_cluster_and_version_>=_v1.22.0 (0.00s) --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_<_v1.22.0 (0.00s) --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_>=_v1.22.0 (0.00s) --- PASS: TestIsKubernetesVersionSupported/management_cluster_and_version_>=_v1.23.0 (0.00s) PASS E1115 03:38:24.298579 11541 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory" E1115 03:38:24.298631 11541 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-330002394/tls.crt: no such file or directory" I1115 03:38:24.298665 11541 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server" ok sigs.k8s.io/cluster-api/controlplane/kubeadm/internal 188.195s === RUN TestEtcdMembers_WithErrors --- PASS: TestEtcdMembers_WithErrors (0.00s) === RUN TestEtcdMembers_WithSuccess --- PASS: TestEtcdMembers_WithSuccess (0.00s) ... skipping 288 lines ... I1115 03:35:41.768356 11899 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourcesetbinding" I1115 03:35:41.867270 11899 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}} I1115 03:35:41.968856 11899 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1 I1115 03:35:41.969710 11899 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" I1115 03:35:41.969778 11899 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1 I1115 03:35:42.050570 11899 clusterresourcesetbinding_controller.go:84] "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-r5av6c"} [32m•[0mE1115 03:35:42.087128 11899 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" I1115 03:35:43.150203 11899 clusterresourcesetbinding_controller.go:84] "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-mepdtz"} [32m•[0mE1115 03:35:43.191111 11899 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" [90m------------------------------[0m [91m[1m• Failure [11.093 seconds][0m ClusterResourceSet Reconciler [90m/home/prow/go/src/sigs.k8s.io/cluster-api/exp/addons/controllers/clusterresourceset_controller_test.go:40[0m [91m[1mShould reconcile a ClusterResourceSet when a resource is created that is part of ClusterResourceSet resources [It][0m ... skipping 8 lines ... [90m------------------------------[0m [1mSTEP[0m: Creating the Cluster [1mSTEP[0m: Creating the remote Cluster kubeconfig [1mSTEP[0m: Creating a Secret and a ConfigMap with ConfigMap in their data field [1mSTEP[0m: Verifying ClusterResourceSetBinding is created with cluster owner reference [1mSTEP[0m: Deleting the Kubeconfigsecret E1115 03:35:54.283633 11899 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" E1115 03:35:55.425176 11899 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" [32m•[0m2022/11/15 03:35:56 http: TLS handshake error from 127.0.0.1:36984: EOF E1115 03:35:56.459687 11899 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" E1115 03:35:57.474798 11899 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" [32m•[0mI1115 03:35:57.475560 11899 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" I1115 03:35:57.475599 11899 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" E1115 03:35:57.475687 11899 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory" E1115 03:35:57.475716 11899 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-721962873/tls.crt: no such file or directory" I1115 03:35:57.475688 11899 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server" [91m[1mSummarizing 1 Failure:[0m [91m[1m[Fail] [0m[90mClusterResourceSet Reconciler [0m[91m[1m[It] Should reconcile a ClusterResourceSet when a resource is created that is part of ClusterResourceSet resources [0m [37m/home/prow/go/src/sigs.k8s.io/cluster-api/exp/addons/controllers/clusterresourceset_controller_test.go:307[0m [1m[91mRan 5 of 5 Specs in 30.717 seconds[0m [1m[91mFAIL![0m -- [32m[1m4 Passed[0m | [91m[1m1 Failed[0m | [33m[1m0 Pending[0m | [36m[1m0 Skipped[0m --- FAIL: TestAPIs (30.72s) FAIL FAIL sigs.k8s.io/cluster-api/exp/addons/controllers 30.813s ? sigs.k8s.io/cluster-api/exp/addons/controllers/predicates [no test files] === RUN TestMachinePoolDefault === RUN TestMachinePoolDefault/for_MachinePool === RUN TestMachinePoolDefault/for_MachinePool/validate-on-create === RUN TestMachinePoolDefault/for_MachinePool/validate-on-update === RUN TestMachinePoolDefault/for_MachinePool/validate-on-delete ... skipping 58 lines ... --- PASS: TestReconcileMachinePoolBootstrap/new_machinepool,_no_bootstrap_config_or_data (0.00s) --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_data_should_not_change (0.00s) --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_provider_is_to_not_ready (0.00s) === RUN TestReconcileMachinePoolInfrastructure === RUN TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready === RUN TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed E1115 03:35:32.518614 12110 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 92 lines ... [32m•[0mI1115 03:35:45.111821 12110 machinepool_controller_noderef.go:90] "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes" [32m•[0mI1115 03:35:45.134556 12110 machinepool_controller_noderef.go:90] "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes" [32m•[0mI1115 03:35:45.136520 12110 machinepool_controller_phases.go:268] "msg"="Infrastructure provider is not ready, requeuing" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" [32m•[0mI1115 03:35:45.164547 12110 machinepool_controller_noderef.go:90] "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes" [32m•[0mI1115 03:35:45.170351 12110 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}}} I1115 03:35:45.192125 12110 machinepool_controller_noderef.go:90] "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes" [32m•[0m[32m•[0mE1115 03:35:45.194639 12110 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory" E1115 03:35:45.194695 12110 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-690329012/tls.crt: no such file or directory" E1115 03:35:45.194716 12110 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory" E1115 03:35:45.194749 12110 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-690329012/tls.crt: no such file or directory" I1115 03:35:45.194853 12110 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server" [1m[32mRan 9 of 9 Specs in 12.691 seconds[0m [1m[32mSUCCESS![0m -- [32m[1m9 Passed[0m | [91m[1m0 Failed[0m | [33m[1m0 Pending[0m | [36m[1m0 Skipped[0m --- PASS: TestAPIs (12.69s) PASS ok sigs.k8s.io/cluster-api/exp/controllers 12.940s ? 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 201 lines ... I1115 03:36:08.332541 15081 server.go:121] controller-runtime/webhook "msg"="registering webhook" "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset" I1115 03:36:08.332663 15081 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server" I1115 03:36:08.333524 15081 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate" I1115 03:36:08.333761 15081 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher" I1115 03:36:08.333833 15081 server.go:199] controller-runtime/webhook "msg"="serving webhook server" "host"="" "port"=45245 [32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0m[32m•[0mI1115 03:36:09.086963 15081 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server" E1115 03:36:09.087235 15081 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed" E1115 03:36:09.087308 15081 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-889420093/tls.crt: no such file or directory" [1m[32mRan 14 of 14 Specs in 7.262 seconds[0m [1m[32mSUCCESS![0m -- [32m[1m14 Passed[0m | [91m[1m0 Failed[0m | [33m[1m0 Pending[0m | [36m[1m0 Skipped[0m --- PASS: TestPatch (7.26s) === 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.037s FAIL make: *** [Makefile:116: test] Error 1