NMI retries and ticker for periodic sync reconcile #272

aramase · 2019-07-02T22:43:18Z

Reason for Change:

Wrap list pod ids call with retries
Filter assigned ids based on state in NMI
Change the status code to 404 instead of 403 when no valid assigned ids found after retries.
Add a ticker to periodically run sync cycle to reconcile any crds that are in error state. This is required because if no pod events are generated, then the sync loop will never get triggered to resync.
Make the sync retry interval configurable

Issue Fixed:

fixes #257

Notes for Reviewers:

kkmsft · 2019-07-03T00:57:15Z

pkg/crd/crd.go

@@ -267,7 +267,7 @@ func (c *Client) ListPodIds(podns, podname string) (*[]aadpodid.AzureIdentity, e

 	var matchedIds []aadpodid.AzureIdentity
 	for _, v := range azAssignedIDList.(*aadpodid.AzureAssignedIdentityList).Items {
-		if v.Spec.Pod == podname && v.Spec.PodNamespace == podns {
+		if v.Spec.Pod == podname && v.Spec.PodNamespace == podns && v.Status.Status == "Assigned" {


Can we make these states a constant ?

That was my initial plan, but the only confusion is IdentityCreated is an int (EventType) in the v1 pkg.

kkmsft · 2019-07-03T00:58:35Z

pkg/mic/mic.go

 	glog.Info("Sync thread started.")
 	var event aadpodid.EventType
 	for {
 		select {
 		case <-exit:
 			return
 		case event = <-c.EventChannel:
+			glog.V(6).Infof("Received event: %v", event)
+		case <-ticker.C:
+			glog.V(6).Infof("Running sync retry loop")
 		}

 		stats.Init()
 		// This is the only place where the AzureAssignedIdentity creation is initiated.
 		begin := time.Now()
 		workDone := false
 		glog.V(6).Infof("Received event: %v", event)


What will event show here ?

kkmsft · 2019-07-03T00:59:56Z

pkg/nmi/server/server.go

 		msg := fmt.Sprintf("no AzureAssignedIdentity found for pod:%s/%s", podns, podname)
 		logger.Errorf("%s, %+v", msg, err)
-		http.Error(w, msg, http.StatusForbidden)
+		http.Error(w, msg, http.StatusNotFound)


hosthandler and mishandler looks identical through most parts.

Can you please unify the new code which you are adding into one single function.

I'll add this as a TODO and refactor in the next PR. Have a few questions on why we check filter identities using force namespaced only in 1 handler and not another. We can go over that during the review.

kkmsft · 2019-07-03T01:00:59Z

pkg/nmi/server/server.go

+		logger.Warningf("failed to get assigned ids for pod:%s/%s, retrying attempt: %d", podns, podname, attempt)
+		time.Sleep(listPodIDsRetryIntervalInSeconds * time.Second)
+	}
+	return nil, fmt.Errorf("getting assigned identities for pod %s/%s failed after %d attempts. Error: %v", podns, podname, maxAttempts, err)


will this error propagate to the caller in the application ?

Yeah, this will be propagated if it fails after retries.

kkmsft · 2019-07-03T01:03:01Z

pkg/nmi/server/server.go

+		}
+		attempt++
+		logger.Warningf("failed to get assigned ids for pod:%s/%s, retrying attempt: %d", podns, podname, attempt)
+		time.Sleep(listPodIDsRetryIntervalInSeconds * time.Second)


Where do we break if we go >= attempt

kkmsft · 2019-07-03T01:07:41Z

pkg/nmi/server/server.go

+	for {
+		podIDs, err = kubeClient.ListPodIds(podns, podname)
+		if err == nil && len(*podIDs) != 0 {
+			if len(rqClientID) == 0 {


there are two kinds of error, one is that after a few seconds, we still did not find the AzureAssignedIdentity and another is that it never moved to Assigned. Not able to gather that different from retry attempts and varying time durations for them..?

The retry attempts are not different based on the states. The final desired state is Assigned. So I think this encompasses all possible scenarios.

update retry

aramase · 2019-07-05T07:13:48Z

Ran 10 of 10 Specs in 4998.515 seconds
SUCCESS! -- 10 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAADPodIdentity (4998.52s)
PASS
ok github.com/Azure/aad-pod-identity/test/e2e 4998.532s

aramase · 2019-07-05T20:20:34Z

test/e2e/aadpodidentity_test.go

@@ -111,7 +111,7 @@ var _ = Describe("Kubernetes cluster using aad-pod-identity", func() {
 		fmt.Println("\nTearing down the test environment...")

 		// Ensure a clean cluster after the end of each test
-		cmd := exec.Command("kubectl", "delete", "AzureIdentity,AzureIdentityBinding,AzureAssignedIdentity", "--all")
+		cmd := exec.Command("kubectl", "delete", "AzureIdentity,AzureIdentityBinding", "--all")


Removing azureassignedidentity from the delete command. It should be deleted by MIC once the identity and binding are removed and it's a good test to ensure we reliably delete the assigned identities.

if that is the exception we should add the check at the end to see if no AzureAssignedIdentities exists and fail the test if it does.

We already ensure the length of azureassignedidentities is equal to 0 at the end of AfterEach.

kkmsft · 2019-07-09T00:23:47Z

Makefile

@@ -141,7 +141,7 @@ e2e:

 .PHONY: unit-test
 unit-test:
-	go test $(shell go list ./... | grep -v /test/e2e) -v
+	go test -count=1 $(shell go list ./... | grep -v /test/e2e) -v


What is the usage of count here ?

It's to ensure the test runs at least once instead of showing the cached result.

kkmsft · 2019-07-09T00:33:21Z

pkg/crd/crd.go

@@ -268,7 +268,11 @@ func (c *Client) ListPodIds(podns, podname string) (*[]aadpodid.AzureIdentity, e
 	var matchedIds []aadpodid.AzureIdentity
 	for _, v := range azAssignedIDList.(*aadpodid.AzureAssignedIdentityList).Items {
 		if v.Spec.Pod == podname && v.Spec.PodNamespace == podns {
-			matchedIds = append(matchedIds, *v.Spec.AzureIdentityRef)
+			for _, desiredState := range assignedIDStates {
+				if v.Status.Status == desiredState {


strings.EqualFold ? or compareState function which we can change as per version ?

kkmsft · 2019-07-09T00:41:25Z

pkg/nmi/server/server.go

+func listPodIDsInCreatedStateWithRetries(ctx context.Context, kubeClient k8s.Client, logger *log.Entry, podns, podname, rqClientID string, maxAttempts int) (*[]aadpodid.AzureIdentity, error) {
+	// created and assigned states are added to statesToCheck. This is to ensure if the call is made after the assigned identity is in assigned state
+	// for the pod, we shouldn't fail on the hard check for created state. Both states are accepted values for passing first check.
+	return listPodIDsWithRetry(ctx, kubeClient, logger, podns, podname, rqClientID, []string{aadpodid.AssignedIDCreated, aadpodid.AssignedIDAssigned}, maxAttempts)


Why are both state assigned ids added when the function name indicates we are going to gather Created ones.

kkmsft · 2019-07-09T00:42:05Z

pkg/nmi/server/server.go

 		logger.Errorf("%s, %+v", msg, err)
-		http.Error(w, msg, http.StatusForbidden)
+		http.Error(w, msg, http.StatusNotFound)


Why do we have to do it two times ? Shouldn't we check and do accordingly ?

aramase · 2019-07-10T17:58:20Z

cmd/mic/main.go

@@ -24,6 +26,8 @@ func main() {
 	flag.StringVar(&cloudconfig, "cloudconfig", "", "Path to cloud config e.g. Azure.json file")
 	flag.BoolVar(&forceNamespaced, "forceNamespaced", false, "Forces namespaced identities, binding, and assignment")
 	flag.BoolVar(&versionInfo, "version", false, "Prints the version information")
+	flag.StringVar(&syncRetryInterval, "syncRetryInterval", "3600s", "The interval in seconds at which sync loop should periodically check for errors and reconcile.")


Change to duration var

aramase · 2019-07-10T23:05:35Z

Ran 11 of 11 Specs in 3839.814 seconds
SUCCESS! -- 11 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAADPodIdentity (3839.81s)
PASS
ok  	github.com/Azure/aad-pod-identity/test/e2e	3839.837s

kkmsft · 2019-07-11T01:01:30Z

pkg/crd/crd.go

 	for _, v := range azAssignedIDList.(*aadpodid.AzureAssignedIdentityList).Items {
 		if v.Spec.Pod == podname && v.Spec.PodNamespace == podns {
-			matchedIds = append(matchedIds, *v.Spec.AzureIdentityRef)


Can we please add a comment in the next PR indicating the backward compatibility aspects.

kkmsft · 2019-07-11T01:02:26Z

test/e2e/template/deployment-rbac.yaml

@@ -85,6 +85,8 @@ metadata:
  name: nmi
  namespace: {{.Namespace}}
 spec:
+  updateStrategy:


What is the significance of this ?

kkmsft · 2019-07-11T01:07:27Z

pkg/nmi/server/server.go

+		}
+		logger.Warningf("failed to get assigned ids for pod:%s/%s in ASSIGNED state, retrying attempt: %d", podns, podname, attempt)
+	}
+	return nil, fmt.Errorf("getting assigned identities for pod %s/%s in ASSIGNED state failed after %d attempts. Error: %v", podns, podname, 2*maxAttemptsPerCheck, err)


It would be good to have the duration in the error logs on how much it tried to do retry.

aramase force-pushed the nmi-retry branch from 14a770e to ed9dca1 Compare July 2, 2019 22:44

kkmsft reviewed Jul 3, 2019

View reviewed changes

nmi retry and sync retry loop

cbc9374

update retry

aramase force-pushed the nmi-retry branch from 12899ab to cbc9374 Compare July 3, 2019 06:53

reduce retry count, update tests, check context

51ed824

aramase commented Jul 5, 2019

View reviewed changes

aramase added 2 commits July 5, 2019 13:20

remove dead code

53865c8

pass sync duration

a89d143

aramase changed the title ~~[WIP] NMI retries and ticker for periodic sync reconcile~~ NMI retries and ticker for periodic sync reconcile Jul 8, 2019

update retry logic based on states

c358db9

kkmsft reviewed Jul 9, 2019

View reviewed changes

aramase added 2 commits July 9, 2019 13:11

return map from list pod ids

b64e15b

return diff error

99401bd

aramase commented Jul 10, 2019

View reviewed changes

ensure backward compat

62e3502

kkmsft reviewed Jul 11, 2019

View reviewed changes

kkmsft merged commit 5ff008a into Azure:master Jul 11, 2019

aramase deleted the nmi-retry branch July 11, 2019 17:24

aramase mentioned this pull request Jul 15, 2019

Update error status code based on state #292

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

NMI retries and ticker for periodic sync reconcile #272

NMI retries and ticker for periodic sync reconcile #272

aramase commented Jul 2, 2019

kkmsft Jul 3, 2019

aramase Jul 3, 2019

kkmsft Jul 3, 2019

kkmsft Jul 3, 2019

kkmsft Jul 9, 2019

aramase Jul 9, 2019

kkmsft Jul 3, 2019

aramase Jul 3, 2019

kkmsft Jul 3, 2019

kkmsft Jul 3, 2019

aramase Jul 3, 2019

aramase commented Jul 5, 2019

aramase Jul 5, 2019

kkmsft Jul 9, 2019

aramase Jul 9, 2019

kkmsft Jul 9, 2019

aramase Jul 9, 2019

kkmsft Jul 9, 2019

kkmsft Jul 9, 2019

kkmsft Jul 9, 2019

aramase Jul 10, 2019

aramase commented Jul 10, 2019

kkmsft Jul 11, 2019

kkmsft Jul 11, 2019

kkmsft Jul 11, 2019

NMI retries and ticker for periodic sync reconcile #272

NMI retries and ticker for periodic sync reconcile #272

Conversation

aramase commented Jul 2, 2019

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

aramase commented Jul 5, 2019

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

aramase commented Jul 10, 2019

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment