services/device/deviced/internal/impl: fix restart policy and test

Change the logic in the restart policy implementation to match the
documentation: we should reset the restart time window with each restart.

Add a test case in the unit test to capture this behavior; also fix the unit
test comparison logic to correctly evaluate the RestartWindowBegan field (it was
always passing before).  As a consequence of fixing the comparison logic, a test
case needed updating.

Unrelated: add the app instance version's envelope in the Debug output for
convenience and add a couple todos for some issues noticed.

Change-Id: Idb6072354ad7f3920d9dd07fe30203a3596d6f43
diff --git a/services/device/deviced/internal/impl/app_service.go b/services/device/deviced/internal/impl/app_service.go
index 8bcca87..89bfdd1 100644
--- a/services/device/deviced/internal/impl/app_service.go
+++ b/services/device/deviced/internal/impl/app_service.go
@@ -1202,6 +1202,10 @@
 	if startSystemName != systemName {
 		return verror.New(verror.ErrNoAccess, ctx, "Not allowed to resume an application under a different system name.")
 	}
+
+	// TODO(caprita): We should reset the Restarts and RestartWindowBegan
+	// fields in the instance info when the instance is started with Run.
+
 	return i.runner.run(ctx, instanceDir)
 }
 
@@ -1677,6 +1681,8 @@
 
 Cmd: {{printf "%+v" .Cmd}}
 
+Envelope: {{printf "%+v" .Envelope}}
+
 Info: {{printf "%+v" .Info}}
 
 Principal: {{.PrincipalType}}
@@ -1696,6 +1702,7 @@
 	debugInfo := struct {
 		InstanceDir, SystemName, StartSystemName string
 		Cmd                                      *exec.Cmd
+		Envelope                                 *application.Envelope
 		Info                                     *instanceInfo
 		Principal                                security.Principal
 		PrincipalType                            string
@@ -1720,6 +1727,12 @@
 		debugInfo.Cmd = cmd
 	}
 
+	if envelope, err := loadEnvelopeForInstance(ctx, instanceDir); err != nil {
+		return "", err
+	} else {
+		debugInfo.Envelope = envelope
+	}
+
 	switch sa := i.runner.securityAgent; {
 	case sa != nil && sa.keyMgr != nil:
 		// Try connecting to principal, if fails try serving, then
diff --git a/services/device/deviced/internal/impl/applife/app_life_test.go b/services/device/deviced/internal/impl/applife/app_life_test.go
index 9dcdb0d..ec3c526 100644
--- a/services/device/deviced/internal/impl/applife/app_life_test.go
+++ b/services/device/deviced/internal/impl/applife/app_life_test.go
@@ -624,6 +624,9 @@
 // envelope.
 func verifyAppPeerBlessings(t *testing.T, ctx, pubCtx *context.T, instanceDebug string, e *application.Envelope) {
 	// Extract the blessings from the debug output
+	//
+	// TODO(caprita): This is flaky, since the '...' peer pattern may not be
+	// the first one in the sorted pattern list.  See v.io/i/680
 	blessingRE := regexp.MustCompile(`Blessings\s?\n\s?\.\.\.\s*([^\n]+)`)
 	blessingMatches := blessingRE.FindStringSubmatch(instanceDebug)
 	if len(blessingMatches) < 2 {
diff --git a/services/device/deviced/internal/impl/restart_policy.go b/services/device/deviced/internal/impl/restart_policy.go
index 465d0e0..dc4a8af 100644
--- a/services/device/deviced/internal/impl/restart_policy.go
+++ b/services/device/deviced/internal/impl/restart_policy.go
@@ -46,6 +46,7 @@
 
 	if instance.Restarts < envelope.Restarts {
 		instance.Restarts++
+		instance.RestartWindowBegan = time.Now()
 		return true
 	}
 
diff --git a/services/device/deviced/internal/impl/restart_policy_test.go b/services/device/deviced/internal/impl/restart_policy_test.go
index 4e3ab8f..046377e 100644
--- a/services/device/deviced/internal/impl/restart_policy_test.go
+++ b/services/device/deviced/internal/impl/restart_policy_test.go
@@ -73,11 +73,11 @@
 			},
 			&instanceInfo{
 				Restarts:           1,
-				RestartWindowBegan: time.Now(),
+				RestartWindowBegan: time.Date(2015, time.December, 25, 12, 0, 0, 0, time.UTC),
 			},
 			&instanceInfo{
 				Restarts:           1,
-				RestartWindowBegan: time.Now(),
+				RestartWindowBegan: time.Date(2015, time.December, 25, 12, 0, 0, 0, time.UTC),
 			},
 			false,
 		},
@@ -97,11 +97,28 @@
 			},
 			true,
 		},
+		// Every time a restart happens, the beginning of the window
+		// should be reset.
+		{
+			&application.Envelope{
+				Restarts:          2,
+				RestartTimeWindow: time.Minute,
+			},
+			&instanceInfo{
+				Restarts:           1,
+				RestartWindowBegan: time.Now().Add(-10 * time.Second),
+			},
+			&instanceInfo{
+				Restarts:           2,
+				RestartWindowBegan: time.Now(),
+			},
+			true,
+		},
 	}
 
-	for _, tv := range testVectors {
+	for ti, tv := range testVectors {
 		if got, want := nbr.decide(tv.envelope, tv.info), tv.decision; got != want {
-			t.Errorf("basicDecisionPolicy decide: got %v, want %v", got, want)
+			t.Errorf("Test case #%d: basicDecisionPolicy decide: got %v, want %v", ti, got, want)
 		}
 
 		if got, want := tv.info.Restarts, tv.wantInfo.Restarts; got != want {
@@ -109,8 +126,8 @@
 		}
 
 		// Times should be "nearly" same.
-		if got, want := tv.info.RestartWindowBegan, tv.wantInfo.RestartWindowBegan; !(got.Sub(want) < time.Second) && (got.Sub(want) > 0) {
-			t.Errorf("basicDecisionPolicy instanceInfo RestartTimeBegan got %v, want %v", got, want)
+		if got, want := tv.info.RestartWindowBegan, tv.wantInfo.RestartWindowBegan; !((got.Sub(want) < time.Second) && (got.Sub(want) >= 0)) {
+			t.Errorf("Test case #%d: basicDecisionPolicy instanceInfo RestartTimeBegan got %v, want %v", ti, got, want)
 		}
 	}
 }