Repository: kubernetes-sigs/cloud-provider-azure (go)

Issue:
If nodes are are not in a ready state when the controller manager boots, the cache is stale causing 15 min delay of LB deployment
<!-- Please use this template while reporting a bug and provide as much info as possible. Not doing so may result in your bug not being addressed in a timely manner. Thanks!
-->


**What happened**:
When adding functionality to the e2e tests in https://github.com/kubernetes-sigs/cluster-api-provider-azure/issues/857 for CAPZ, I found the e2e tests would fail if run against a single control plane node cluster.  This would occasionally happen when running multi-node control plane clusters as well.  This was initially reported with some of the message in #338

What happens is the control manager comes [online and queries for azure machines power status.](https://github.com/kubernetes/kubernetes/blob/ec560b9737537be8c688776461bc700e8ddedb9d/staging/src/k8s.io/legacy-cloud-providers/azure/azure_vmss.go#L211)  Since the machines are not available yet [they are not in the cache.](https://github.com/kubernetes/kubernetes/blob/ec560b9737537be8c688776461bc700e8ddedb9d/staging/src/k8s.io/legacy-cloud-providers/azure/azure_vmss_cache.go#L307) When the request comes in for the [load balancer the cache is queried](https://github.com/kubernetes/kubernetes/blob/ec560b9737537be8c688776461bc700e8ddedb9d/staging/src/k8s.io/legacy-cloud-providers/azure/azure_vmss.go#L1196) and reports that the node [does not exist as a VMAS and attempts to run the VMSS code](https://github.com/kubernetes/kubernetes/blob/ec560b9737537be8c688776461bc700e8ddedb9d/staging/src/k8s.io/legacy-cloud-providers/azure/azure_vmss.go#L1217) hence the following error message.  When it is found the in the cache it goes down the [correct code path](https://github.com/kubernetes/kubernetes/blob/master/staging/src/k8s.io/legacy-cloud-providers/azure/azure_vmss.go#L1272).

```
E0802 23:30:06.928574       1 azure_vmss.go:1116] EnsureHostInPool(default/ingress-nginx-ilb): backendPoolID(/subscriptions/b9d9436a-0c07-4fe8-b779-2c1030bd7997/resourceGroups/capz-e2e-72fll1/providers/Microsoft.Network/loadBalancers/capz-e2e-72fll1-internal/backendAddressPools/capz-e2e-72fll1) - failed to ensure host in pool: "not a vmss instance"
```



I was able to confirm the cache was missing the node by adding some custom logs to the controller-manager. The initial [request to the cache](https://github.com/kubernetes/kubernetes/blob/master/staging/src/k8s.io/legacy-cloud-providers/azure/azure_vmss_cache.go#L277) doesn't have the nodes:

```
I0802 23:27:42.217347       1 azure_vmss.go:309] Can not extract scale set name from providerID (azure:///subscriptions/b9d9436a-0c07-4fe8-b779-2c1030bd7997/resourceGroups/capz-e2e-72fll1/providers/Microsoft.Compute/virtualMachines/capz-e2e-72fll1-control-plane-wjqp5), assuming it is mananaged by availability set: not a vmss instance
I0802 23:27:42.217487       1 azure_vmss.go:192] JJS: powerstatus node capz-e2e-72fll1-control-plane-wjqp5
I0802 23:27:42.217638       1 azure_vmss_cache.go:238] JJS: enter cache calls for nodes
I0802 23:27:42.217725       1 azure_vmss_cache.go:240] JJS: listing nodes for rg: capz-e2e-72fll1
I0802 23:27:42.651485       1 azure_backoff.go:100] VirtualMachinesClient.List(capz-e2e-72fll1) success
I0802 23:27:42.651641       1 azure_vmss_cache.go:246] JJS: nodes found: %!s(int=1)
I0802 23:27:42.651750       1 azure_vmss_cache.go:249] JJS: adding node to local cache {{%!s(*http.Response=<nil>)} %!s(*compute.Plan=<nil>) %!s(*compute.VirtualMachineProperties=&{0xc001fd3eb0 0xc002022960 <nil> 0xc001f13ea0 0xc0020280a0 <nil> <nil> <nil> <nil>   <nil> <nil> 0xc001fd3fd0 <nil> <nil> 0xc001fd3ea0}) %!s(*[]compute.VirtualMachineExtension=<nil>) %!s(*compute.VirtualMachineIdentity=<nil>) %!s(*[]string=&[1]) %!s(*string=0xc001fd2a60) %!s(*string=0xc001fd2a50) %!s(*string=0xc001fd2a70) %!s(*string=0xc001fd2a80) map[Name:%!s(*string=0xc001fd2a90) creationTimestamp:%!s(*string=0xc001fd2ab0) jobName:%!s(*string=0xc001fd2ad0) kubernetes.io_cluster_capz-e2e-72fll1-control-plane-wjqp5:%!s(*string=0xc001fd2af0) sigs.k8s.io_cluster-api-provider-azure_cluster_capz-e2e-72fll1:%!s(*string=0xc001fd2b10) sigs.k8s.io_cluster-api-provider-azure_role:%!s(*string=0xc001fd2b30)]}
I0802 23:27:42.651962       1 azure_vmss_cache.go:278] JJS: VMAS Nodes: map[capz-e2e-72fll1-control-plane-wjqp5:{}]
I0802 23:27:42.652194       1 azure_vmss_cache.go:280] JJS: asking for node capz-e2e-72fll1-control-plane-wjqp5
I0802 23:27:42.698224       1 azure_instances.go:232] InstanceShutdownByProviderID gets power status "running" for node "capz-e2e-72fll1-control-plane-wjqp5"
```

You can see request for powerstatus here:

```
I0802 23:28:32.709471       1 azure_vmss.go:192] JJS: powerstatus node capz-e2e-72fll1-md-0-q2st9
I0802 23:28:32.709626       1 azure_vmss_cache.go:278] JJS: VMAS Nodes: map[capz-e2e-72fll1-control-plane-wjqp5:{}]
I0802 23:28:32.709652       1 azure_vmss_cache.go:280] JJS: asking for node capz-e2e-72fll1-md-0-q2st9
I0802 23:28:32.709836       1 azure_vmss.go:309] Can not extract scale set name from providerID (azure:///subscriptions/b9d9436a-0c07-4fe8-b779-2c1030bd7997/resourceGroups/capz-e2e-72fll1/providers/Microsoft.Compute/virtualMachines/capz-e2e-72fll1-md-0-q2st9), assuming it is mananaged by availability set: not a vmss instance
```

And request for [EnsureHostsInPool](https://github.com/kubernetes/kubernetes/blob/master/staging/src/k8s.io/legacy-cloud-providers/azure/azure_vmss.go#L1178) doesn't have the VMAS nodes in the cache:

```
I0802 23:30:06.928474       1 azure_vmss.go:1077] JJS: EnsureHostsInPool node capz-e2e-72fll1-md-0-q2st9
I0802 23:30:06.928488       1 azure_vmss_cache.go:278] JJS: VMAS Nodes: map[capz-e2e-72fll1-control-plane-wjqp5:{}]
I0802 23:30:06.928518       1 azure_vmss_cache.go:280] JJS: asking for node capz-e2e-72fll1-md-0-q2st9
I0802 23:30:06.928529       1 azure_vmss.go:1097] JJS: EnsureHostsInPool node false managedby VMAS
I0802 23:30:06.928542       1 azure_vmss.go:1113] JJS: EnsureHostsInPool entered EnsureHostInPool started%!(EXTRA bool=false)
I0802 23:30:06.928549       1 azure_vmss.go:832] ensuring node "capz-e2e-72fll1-md-0-q2st9" of scaleset "" in LB backendpool "/subscriptions/b9d9436a-0c07-4fe8-b779-2c1030bd7997/resourceGroups/capz-e2e-72fll1/providers/Microsoft.Network/loadBalancers/capz-e2e-72fll1-internal/backendAddressPools/capz-e2e-72fll1"
E0802 23:30:06.928574       1 azure_vmss.go:1116] EnsureHostInPool(default/ingress-nginx-ilb): backendPoolID(/subscriptions/b9d9436a-0c07-4fe8-b779-2c1030bd7997/resourceGroups/capz-e2e-72fll1/providers/Microsoft.Network/loadBalancers/capz-e2e-72fll1-internal/backendAddressPools/capz-e2e-72fll1) - failed to ensure host in pool: "not a vmss instance"
```

**What you expected to happen**:

**How to reproduce it**:
Follow the instructions at https://github.com/kubernetes-sigs/cluster-api-provider-azure/issues/857  or create a single node control plane cluster then after the control node is up, add a worker node.

**Anything else we need to know?**:
In multi control plane node clusters, leader election occurs in the controller-manager and causes the cache to reload.  This is why it only happens occasionally in that scenario.  

I believe this could happen if a node is added at a later time and was expected to be in the backend pool but wasn't and so could be important to fix.


**Environment**:
- Kubernetes version (use `kubectl version`): `1.18.6`
- OS (e.g. from /etc/os-release):
- Kernel (e.g. `uname -a`):
- Install tools: CAPZ
- Others:


Pull request description:
Fix availability set cache in vmss cache
<!--  Thanks for sending a pull request!  Here are some tips for you:

1. If this is your first time, please read our contributor guidelines: https://git.k8s.io/community/contributors/guide#your-first-contribution and developer guide https://git.k8s.io/community/contributors/devel/development.md#development-guide
2. Please label this pull request according to what type of issue you are addressing, especially if this is a release targeted pull request. For reference on required PR/issue labels, read here:
https://git.k8s.io/community/contributors/devel/release.md#issue-kind-label
3. Ensure you have added or ran the appropriate tests for your PR: https://git.k8s.io/community/contributors/devel/testing.md
4. If you want *faster* PR reviews, read how: https://git.k8s.io/community/contributors/guide/pull-requests.md#best-practices-for-faster-reviews
5. Follow the instructions for writing a release note: https://git.k8s.io/community/contributors/guide/release-notes.md
6. If the PR is unfinished, see how to mark it: https://git.k8s.io/community/contributors/guide/pull-requests.md#marking-unfinished-pull-requests
-->

**What type of PR is this?**
> Uncomment only one ` /kind <>` line, hit enter to put that in a new line, and remove leading whitespaces from that line:
>
> /kind api-change
> /kind bug
> /kind cleanup
> /kind design
> /kind documentation
> /kind failing-test
> /kind feature
> /kind flake

 /kind bug

**What this PR does / why we need it**:  This fixes a bug affecting clusters with virtual machines when vmType is set to "vmss". What happens is the control manager comes online and queries for azure machines power status. Since the machines are not available yet they are not in the cache. When the request comes in for the load balancer the cache is queried and reports that the node does not exist as a VMAS and attempts to run the VMSS code hence the following error message: `failed: not a vmss instance`. The same error also occurs when trying to expose a load balancer service. When it is found the cache it goes down the correct code path.

This adds logic to the vmss cache to refresh the availability set cache if the node it is querying for has joined the cluster since the last cache refresh, or if the cache has expired. Note that this approach minimizes cache refreshes by not refreshing unless necessary, but it does add extra GET API calls whenever a new node joins the cluster. This can be skipped altogether with the `DisableAvailabilitySetNodes` flag that is already implemented. It's not perfect but it will fix most scenarios for CAPZ. In the future, I'd like to propose a new "mixed" or "hybrid" VMSet implementation that is truly aware of both VMs and VMSS nodes as a more long term fix.

**Which issue(s) this PR fixes**:
<!-- 
*Automatically closes linked issue when PR is merged.
Usage: `Fixes #<issue number>`, or `Fixes (paste link of issue)`.
_If PR is about `failing-tests or flakes`, please post the related issues/tests in a comment and do not use `Fixes`_*
-->
Fixes #363 

**Special notes for your reviewer**: @feiskyer if I want this fix to make it back into the in tree provider, what's the best way to proceed?


**Release note**:
```
Fix availability set cache in vmss cache
```


Patch:
diff --git a/Makefile b/Makefile
index 189a0d71a..814daec92 100644
--- a/Makefile
+++ b/Makefile
@@ -27,7 +27,7 @@ TEST_MANIFEST ?= linux
 # build hyperkube image when specified
 K8S_BRANCH ?=
 # Only run conformance tests by default (non-serial and non-slow)
-# Note autoscaling tests would be skiped as well.
+# Note autoscaling tests would be skipped as well.
 CCM_E2E_ARGS ?= -ginkgo.skip=\\[Serial\\]\\[Slow\\]
 #The test args for Kubernetes e2e tests
 TEST_E2E_ARGS ?= '--ginkgo.focus=Port\sforwarding'
diff --git a/pkg/provider/azure.go b/pkg/provider/azure.go
index 0cd32d41c..98f122697 100644
--- a/pkg/provider/azure.go
+++ b/pkg/provider/azure.go
@@ -253,6 +253,8 @@ type Cloud struct {
 	ipv6DualStackEnabled bool
 	// Lock for access to node caches, includes nodeZones, nodeResourceGroups, and unmanagedNodes.
 	nodeCachesLock sync.RWMutex
+	// nodeNames holds current nodes for tracking added nodes in VM caches.
+	nodeNames sets.String
 	// nodeZones is a mapping from Zone to a sets.String of Node's names in the Zone
 	// it is updated by the nodeInformer
 	nodeZones map[string]sets.String
@@ -321,6 +323,7 @@ func NewCloudWithoutFeatureGates(configReader io.Reader) (*Cloud, error) {
 	}
 
 	az := &Cloud{
+		nodeNames:          sets.NewString(),
 		nodeZones:          map[string]sets.String{},
 		nodeResourceGroups: map[string]string{},
 		unmanagedNodes:     sets.NewString(),
@@ -787,6 +790,9 @@ func (az *Cloud) updateNodeCaches(prevNode, newNode *v1.Node) {
 	defer az.nodeCachesLock.Unlock()
 
 	if prevNode != nil {
+		// Remove from nodeNames cache.
+		az.nodeNames.Delete(prevNode.ObjectMeta.Name)
+
 		// Remove from nodeZones cache.
 		prevZone, ok := prevNode.ObjectMeta.Labels[consts.LabelFailureDomainBetaZone]
 		if ok && az.isAvailabilityZone(prevZone) {
@@ -810,6 +816,9 @@ func (az *Cloud) updateNodeCaches(prevNode, newNode *v1.Node) {
 	}
 
 	if newNode != nil {
+		// Add to nodeNames cache.
+		az.nodeNames.Insert(newNode.ObjectMeta.Name)
+
 		// Add to nodeZones cache.
 		newZone, ok := newNode.ObjectMeta.Labels[consts.LabelFailureDomainBetaZone]
 		if ok && az.isAvailabilityZone(newZone) {
@@ -881,6 +890,22 @@ func (az *Cloud) GetNodeResourceGroup(nodeName string) (string, error) {
 	return az.ResourceGroup, nil
 }
 
+// GetNodeNames returns a set of all node names in the k8s cluster.
+func (az *Cloud) GetNodeNames() (sets.String, error) {
+	// Kubelet won't set az.nodeInformerSynced, return nil.
+	if az.nodeInformerSynced == nil {
+		return nil, nil
+	}
+
+	az.nodeCachesLock.RLock()
+	defer az.nodeCachesLock.RUnlock()
+	if !az.nodeInformerSynced() {
+		return nil, fmt.Errorf("node informer is not synced when trying to GetNodeNames")
+	}
+
+	return sets.NewString(az.nodeNames.List()...), nil
+}
+
 // GetResourceGroups returns a set of resource groups that all nodes are running on.
 func (az *Cloud) GetResourceGroups() (sets.String, error) {
 	// Kubelet won't set az.nodeInformerSynced, always return configured resourceGroup.
diff --git a/pkg/provider/azure_vmss.go b/pkg/provider/azure_vmss.go
index 8e90903e9..a94352b03 100644
--- a/pkg/provider/azure_vmss.go
+++ b/pkg/provider/azure_vmss.go
@@ -79,8 +79,9 @@ type nodeIdentity struct {
 type ScaleSet struct {
 	*Cloud
 
-	// availabilitySet is also required for ScaleSet because some instances
-	// (e.g. master nodes) may not belong to any scale sets.
+	// availabilitySet is also required for scaleSet because some instances
+	// (e.g. control plane nodes) may not belong to any scale sets.
+	// this also allows for clusters with both VM and VMSS nodes.
 	availabilitySet VMSet
 
 	vmssCache                 *azcache.TimedCache
diff --git a/pkg/provider/azure_vmss_cache.go b/pkg/provider/azure_vmss_cache.go
index 8a98443f0..3d957ef4f 100644
--- a/pkg/provider/azure_vmss_cache.go
+++ b/pkg/provider/azure_vmss_cache.go
@@ -57,6 +57,11 @@ type vmssEntry struct {
 	lastUpdate    time.Time
 }
 
+type availabilitySetEntry struct {
+	vmNames   sets.String
+	nodeNames sets.String
+}
+
 func (ss *ScaleSet) newVMSSCache() (*azcache.TimedCache, error) {
 	getter := func(key string) (interface{}, error) {
 		localCache := &sync.Map{} // [vmssName]*vmssEntry
@@ -272,7 +277,7 @@ func (ss *ScaleSet) deleteCacheForNode(nodeName string) error {
 
 func (ss *ScaleSet) newAvailabilitySetNodesCache() (*azcache.TimedCache, error) {
 	getter := func(key string) (interface{}, error) {
-		localCache := sets.NewString()
+		vmNames := sets.NewString()
 		resourceGroups, err := ss.GetResourceGroups()
 		if err != nil {
 			return nil, err
@@ -286,11 +291,22 @@ func (ss *ScaleSet) newAvailabilitySetNodesCache() (*azcache.TimedCache, error)
 
 			for _, vm := range vmList {
 				if vm.Name != nil {
-					localCache.Insert(*vm.Name)
+					vmNames.Insert(*vm.Name)
 				}
 			}
 		}
 
+		// store all the node names in the cluster when the cache data was created.
+		nodeNames, err := ss.GetNodeNames()
+		if err != nil {
+			return nil, err
+		}
+
+		localCache := availabilitySetEntry{
+			vmNames:   vmNames,
+			nodeNames: nodeNames,
+		}
+
 		return localCache, nil
 	}
 
@@ -312,6 +328,16 @@ func (ss *ScaleSet) isNodeManagedByAvailabilitySet(nodeName string, crt azcache.
 		return false, err
 	}
 
-	availabilitySetNodes := cached.(sets.String)
-	return availabilitySetNodes.Has(nodeName), nil
+	cachedNodes := cached.(availabilitySetEntry).nodeNames
+	// if the node is not in the cache, assume the node has joined after the last cache refresh and attempt to refresh the cache.
+	if !cachedNodes.Has(nodeName) {
+		klog.V(2).Infof("Node %s has joined the cluster since the last VM cache refresh, refreshing the cache", nodeName)
+		cached, err = ss.availabilitySetNodesCache.Get(availabilitySetNodesKey, azcache.CacheReadTypeForceRefresh)
+		if err != nil {
+			return false, err
+		}
+	}
+
+	cachedVMs := cached.(availabilitySetEntry).vmNames
+	return cachedVMs.Has(nodeName), nil
 }


Test patch:
diff --git a/pkg/provider/azure_test.go b/pkg/provider/azure_test.go
index 7bf1a27f0..27cd31749 100644
--- a/pkg/provider/azure_test.go
+++ b/pkg/provider/azure_test.go
@@ -3225,6 +3225,7 @@ func TestUpdateNodeCaches(t *testing.T) {
 	az.nodeZones = map[string]sets.String{zone: nodesInZone}
 	az.nodeResourceGroups = map[string]string{"prevNode": "rg"}
 	az.unmanagedNodes = sets.NewString("prevNode")
+	az.nodeNames = sets.NewString("prevNode")
 
 	prevNode := v1.Node{
 		ObjectMeta: metav1.ObjectMeta{
@@ -3241,6 +3242,7 @@ func TestUpdateNodeCaches(t *testing.T) {
 	assert.Equal(t, 0, len(az.nodeZones[zone]))
 	assert.Equal(t, 0, len(az.nodeResourceGroups))
 	assert.Equal(t, 0, len(az.unmanagedNodes))
+	assert.Equal(t, 0, len(az.nodeNames))
 
 	newNode := v1.Node{
 		ObjectMeta: metav1.ObjectMeta{
@@ -3257,6 +3259,7 @@ func TestUpdateNodeCaches(t *testing.T) {
 	assert.Equal(t, 1, len(az.nodeZones[zone]))
 	assert.Equal(t, 1, len(az.nodeResourceGroups))
 	assert.Equal(t, 1, len(az.unmanagedNodes))
+	assert.Equal(t, 1, len(az.nodeNames))
 }
 
 func TestGetActiveZones(t *testing.T) {