plugins/bundle: Include last successful request timestamp in status

This commit updates the bundle plugin to record the last successful
download _attempt_ timestamp in the bundle status. This way Status API
implementations can easily check whether the OPA has been able to
recently check-in for bundle updates.

Fixes open-policy-agent#2009

Signed-off-by: Torin Sandall <torinsandall@gmail.com>

docs/content/management.md

@@ -431,7 +431,7 @@ updates contain status information for OPA itself as well as the
 [Bundles](#bundles) that have been downloaded and activated.
 
 OPA sends status reports whenever one of the following happens:
- 
+
 * Bundles are downloaded and activated -- If the bundle download or activation fails for any reason, the status update
   will include error information describing the failure. This includes Discovery bundles.
 * A plugin state has changed -- All plugin status is reported, and an update to any plugin will
@@ -468,6 +468,8 @@ on the agent, updates will be sent to `/status`.
   "bundles": {
     "http/example/authz": {
       "active_revision": "ABC",
+      "last_request": "2018-01-01T00:00:00.000Z",
+      "last_successful_request": "2018-01-01T00:00:00.000Z",
       "last_successful_download": "2018-01-01T00:00:00.000Z",
       "last_successful_activation": "2018-01-01T00:00:00.000Z",
       "metrics": {
@@ -616,6 +618,8 @@ Status updates contain the following fields:
 | `bundles` | `object` | Set of objects describing the status for each bundle configured with OPA. |
 | `bundles[_].name` | `string` | Name of bundle that the OPA instance is configured to download. |
 | `bundles[_].active_revision` | `string` | Opaque revision identifier of the last successful activation. |
+| `bundles[_].last_request` | `string` | RFC3339 timestamp of last bundle request. This timestamp should be >= to the successful request timestamp in normal operation. |
+| `bundles[_].last_successful_request` | `string` | RFC3339 timestamp of last successful bundle request. This timestamp should be >= to the successful download timestamp in normal operation. |
 | `bundles[_].last_successful_download` | `string` | RFC3339 timestamp of last successful bundle download. |
 | `bundles[_].last_successful_activation` | `string` | RFC3339 timestamp of last successful bundle activation. |
 | `bundles[_].metrics` | `object` | Metrics from the last update of the bundle. |

plugins/bundle/plugin.go

@@ -286,14 +286,18 @@ func (p *Plugin) process(ctx context.Context, name string, u download.Update) {
 		p.status[name].Metrics = metrics.New()
 	}
 
+	p.status[name].SetRequest()
+
 	if u.Error != nil {
 		p.logError(name, "Bundle download failed: %v", u.Error)
 		p.status[name].SetError(u.Error)
 		return
 	}
 
+	p.status[name].LastSuccessfulRequest = p.status[name].LastRequest
+
 	if u.Bundle != nil {
-		p.status[name].SetDownloadSuccess()
+		p.status[name].LastSuccessfulDownload = p.status[name].LastSuccessfulRequest
 
 		p.status[name].Metrics.Timer(metrics.RegoLoadBundles).Start()
 		defer p.status[name].Metrics.Timer(metrics.RegoLoadBundles).Stop()

plugins/bundle/plugin_test.go

@@ -7,6 +7,7 @@ package bundle
 import (
 	"bytes"
 	"context"
+	"errors"
 	"fmt"
 	"net/http"
 	"net/http/httptest"
@@ -15,6 +16,7 @@ import (
 	"sort"
 	"strings"
 	"testing"
+	"time"
 
 	"github.com/open-policy-agent/opa/ast"
 	"github.com/open-policy-agent/opa/bundle"
@@ -1100,6 +1102,49 @@ func TestPluginReconfigure(t *testing.T) {
 	}
 }
 
+func TestPluginRequestVsDownloadTimestamp(t *testing.T) {
+
+	ctx := context.Background()
+	manager := getTestManager()
+	plugin := Plugin{manager: manager, status: map[string]*Status{}, etags: map[string]string{}}
+	bundleName := "test-bundle"
+	plugin.status[bundleName] = &Status{Name: bundleName}
+
+	b := &bundle.Bundle{}
+	b.Manifest.Init()
+
+	// simulate HTTP 200 response from downloader
+	plugin.oneShot(ctx, bundleName, download.Update{Bundle: b})
+
+	if plugin.status[bundleName].LastSuccessfulDownload != plugin.status[bundleName].LastSuccessfulRequest || plugin.status[bundleName].LastSuccessfulDownload != plugin.status[bundleName].LastRequest {
+		t.Fatal("expected last successful request to be same as download and request")
+	}
+
+	// The time resolution is 1ns so sleeping for 1ms should be more than enough.
+	time.Sleep(time.Millisecond)
+
+	// simulate HTTP 304 response from downloader.
+	plugin.oneShot(ctx, bundleName, download.Update{Bundle: nil})
+
+	if plugin.status[bundleName].LastSuccessfulDownload == plugin.status[bundleName].LastSuccessfulRequest || plugin.status[bundleName].LastSuccessfulDownload == plugin.status[bundleName].LastRequest {
+		t.Fatal("expected last successful request to differ from download and request")
+	}
+
+	// simulate HTTP 200 response from downloader
+	plugin.oneShot(ctx, bundleName, download.Update{Bundle: b})
+
+	if plugin.status[bundleName].LastSuccessfulDownload != plugin.status[bundleName].LastSuccessfulRequest || plugin.status[bundleName].LastSuccessfulDownload != plugin.status[bundleName].LastRequest {
+		t.Fatal("expected last successful request to be same as download and request")
+	}
+
+	// simulate error response from downloader
+	plugin.oneShot(ctx, bundleName, download.Update{Error: errors.New("xxx")})
+
+	if plugin.status[bundleName].LastSuccessfulDownload != plugin.status[bundleName].LastSuccessfulRequest || plugin.status[bundleName].LastSuccessfulDownload == plugin.status[bundleName].LastRequest {
+		t.Fatal("expected last successful request to be same as download but different from request")
+	}
+}
+
 func TestUpgradeLegacyBundleToMuiltiBundleSameBundle(t *testing.T) {
 
 	ctx := context.Background()

plugins/bundle/status.go

@@ -25,6 +25,8 @@ type Status struct {
 	ActiveRevision           string          `json:"active_revision,omitempty"`
 	LastSuccessfulActivation time.Time       `json:"last_successful_activation,omitempty"`
 	LastSuccessfulDownload   time.Time       `json:"last_successful_download,omitempty"`
+	LastSuccessfulRequest    time.Time       `json:"last_successful_request,omitempty"`
+	LastRequest              time.Time       `json:"last_request,omitempty"`
 	Code                     string          `json:"code,omitempty"`
 	Message                  string          `json:"message,omitempty"`
 	Errors                   []error         `json:"errors,omitempty"`
@@ -44,6 +46,11 @@ func (s *Status) SetDownloadSuccess() {
 	s.LastSuccessfulDownload = time.Now().UTC()
 }
 
+// SetRequest updates the status object to reflect a download attempt.
+func (s *Status) SetRequest() {
+	s.LastRequest = time.Now().UTC()
+}
+
 // SetError updates the status object to reflect a failure to download or
 // activate. If err is nil, the error status is cleared.
 func (s *Status) SetError(err error) {