all: store an asof date in mode, and use it to guard uploads

As described in golang/go#63218, there were various modes where we
could upload data from before gotelemetry was enabled, or before the
week-long grace period had expired.

Fix this rather explicitly by recording the date that telemetry was
enabled in the mode file, and using this to guard uploads.

There are several places where the logic could be tightened, but I opted
for defensiveness given the late nature of this change.

For golang/go#63218

Change-Id: I9d5f5c5ec9908345697e0e0c21859ad5e34605c6
Reviewed-on: https://go-review.googlesource.com/c/telemetry/+/530995
Reviewed-by: Hyang-Ah Hana Kim <[email protected]>
LUCI-TryBot-Result: Go LUCI <[email protected]>
Reviewed-by: Peter Weinberger <[email protected]>

Author: findleyr

cmd/gotelemetry/main.go

@@ -209,7 +209,8 @@ func runView(_ []string) {
 }
 
 func runEnv(_ []string) {
-	fmt.Println("mode:", it.Mode())
+	m, t := it.Mode()
+	fmt.Printf("mode: %s %s\n", m, t)
 	fmt.Println()
 	fmt.Println("modefile:", it.ModeFile)
 	fmt.Println("localdir:", it.LocalDir)

internal/counter/file.go

@@ -232,6 +232,9 @@ func fileValidity(now time.Time) (int, error) {
 	if err != nil {
 		return 0, err
 	}
+	// TODO(rfindley): once we can rely on telemetry users setting a mode date,
+	// we don't need to implement this heuristic about the existing of json
+	// files.
 	for _, f := range fi {
 		if strings.HasSuffix(f.Name(), ".json") {
 			return int(incr), nil

internal/telemetry/mode.go

@@ -10,6 +10,7 @@ import (
 	"os"
 	"path/filepath"
 	"strings"
+	"time"
 )
 
 // The followings are the process' default Settings.
@@ -42,11 +43,21 @@ func init() {
 
 // SetMode updates the telemetry mode with the given mode.
 // Acceptable values for mode are "on" or "off".
+//
+// SetMode always writes the mode file, and explicitly records the date at
+// which the modefile was updated. This means that calling SetMode with "on"
+// effectively resets the timeout before the next telemetry report is uploaded.
 func SetMode(mode string) error {
 	return ModeFile.SetMode(mode)
 }
 
 func (m ModeFilePath) SetMode(mode string) error {
+	return m.SetModeAsOf(mode, time.Now())
+}
+
+// SetModeAsOf is like SetMode, but accepts an explicit time to use to
+// back-date the mode state. This exists only for testing purposes.
+func (m ModeFilePath) SetModeAsOf(mode string, asofTime time.Time) error {
 	mode = strings.TrimSpace(mode)
 	switch mode {
 	case "on", "off":
@@ -60,25 +71,47 @@ func (m ModeFilePath) SetMode(mode string) error {
 	if err := os.MkdirAll(filepath.Dir(fname), 0755); err != nil {
 		return fmt.Errorf("cannot create a telemetry mode file: %w", err)
 	}
-	data := []byte(mode)
+
+	asof := asofTime.UTC().Format("2006-01-02")
+	// Defensively guarantee that we can parse the asof time.
+	if _, err := time.Parse("2006-01-02", asof); err != nil {
+		return fmt.Errorf("internal error: invalid mode date %q: %v", asof, err)
+	}
+
+	data := []byte(mode + " " + asof)
 	return os.WriteFile(fname, data, 0666)
 }
 
-// Mode returns the current telemetry mode.
-func Mode() string {
+// Mode returns the current telemetry mode, as well as the time that the mode
+// was effective.
+//
+// If there is no effective time, the second result is the zero time.
+func Mode() (string, time.Time) {
 	return ModeFile.Mode()
 }
 
-func (m ModeFilePath) Mode() string {
+func (m ModeFilePath) Mode() (string, time.Time) {
 	fname := string(m)
 	if fname == "" {
-		return "off" // it's likely LocalDir/UploadDir are empty too. Turn off telemetry.
+		return "off", time.Time{} // it's likely LocalDir/UploadDir are empty too. Turn off telemetry.
 	}
 	data, err := os.ReadFile(fname)
 	if err != nil {
-		return "off" // default
+		return "off", time.Time{} // default
 	}
 	mode := string(data)
 	mode = strings.TrimSpace(mode)
-	return mode
+
+	// Forward compatibility for https://go.dev/issue/63142#issuecomment-1734025130
+	//
+	// If the modefile contains a date, return it.
+	if idx := strings.Index(mode, " "); idx >= 0 {
+		d, err := time.Parse("2006-01-02", mode[idx+1:])
+		if err != nil {
+			d = time.Time{}
+		}
+		return mode[:idx], d
+	}
+
+	return mode, time.Time{}
 }

internal/telemetry/mode_test.go

@@ -10,6 +10,7 @@ import (
 	"os"
 	"path/filepath"
 	"testing"
+	"time"
 )
 
 func TestTelemetryDefault(t *testing.T) {
@@ -27,6 +28,7 @@ func TestTelemetryDefault(t *testing.T) {
 		}
 	}
 }
+
 func TestTelemetryModeWithNoModeConfig(t *testing.T) {
 	tmp := t.TempDir()
 	tests := []struct {
@@ -37,14 +39,14 @@ func TestTelemetryModeWithNoModeConfig(t *testing.T) {
 		{"", "off"},
 	}
 	for _, tt := range tests {
-		if got := tt.modefile.Mode(); got != tt.want {
+		if got, _ := tt.modefile.Mode(); got != tt.want {
 			t.Logf("Mode file: %q", tt.modefile)
 			t.Errorf("Mode() = %v, want %v", got, tt.want)
 		}
 	}
 }
 
-func TestTelemetryMode(t *testing.T) {
+func TestSetMode(t *testing.T) {
 	tests := []struct {
 		in      string
 		wantErr bool // want error when setting.
@@ -68,9 +70,36 @@ func TestTelemetryMode(t *testing.T) {
 			if setErr != nil {
 				return
 			}
-			if got := modefile.Mode(); got != tt.in {
+			if got, _ := modefile.Mode(); got != tt.in {
 				t.Errorf("LookupMode() = %q, want %q", got, tt.in)
 			}
 		})
 	}
 }
+
+func TestMode(t *testing.T) {
+	tests := []struct {
+		in       string
+		wantMode string
+		wantTime time.Time
+	}{
+		{"on", "on", time.Time{}},
+		{"on 2023-09-26", "on", time.Date(2023, time.September, 26, 0, 0, 0, 0, time.UTC)},
+		{"off", "off", time.Time{}},
+		{"local", "local", time.Time{}},
+	}
+	tmp := t.TempDir()
+	for i, tt := range tests {
+		t.Run("mode="+tt.in, func(t *testing.T) {
+			fname := filepath.Join(tmp, fmt.Sprintf("modefile%d", i))
+			if err := os.WriteFile(fname, []byte(tt.in), 0666); err != nil {
+				t.Fatal(err)
+			}
+			// Note: the checks below intentionally do not use time.Equal:
+			// we want this exact representation of time.
+			if gotMode, gotTime := ModeFilePath(fname).Mode(); gotMode != tt.wantMode || gotTime != tt.wantTime {
+				t.Errorf("ModeFilePath(contents=%s).Mode() = %q, %v, want %q, %v", tt.in, gotMode, gotTime, tt.wantMode, tt.wantTime)
+			}
+		})
+	}
+}

internal/upload/dates_test.go

@@ -25,7 +25,7 @@ import (
 // doing them subtest() checks the correctness of a single upload to the local server.
 func TestDates(t *testing.T) {
 	skipIfUnsupportedPlatform(t)
-	setup(t)
+	setup(t, "2019-12-01") // back-date the telemetry acceptance
 	defer restore()
 	thisInstant = future(0)
 	finished := counter.Open()
@@ -45,9 +45,40 @@ func TestDates(t *testing.T) {
 	subtest(t) // do and check a report
 
 	// create a lot of tests, and run them
-	const today = "2020-01-24" // same for each test
+	const today = "2020-01-24"
 	const yesterday = "2020-01-23"
 	tests := []Test{ // each date must be different to subvert the parse cache
+		{ // test that existing counters and ready files are not uploaded if telemetry was recently enabled.
+			name:      "beforefirstupload",
+			today:     "2019-12-04",
+			date:      "2019-12-03",
+			begins:    "2019-12-01",
+			ends:      "2019-12-03",
+			readys:    []string{"2019-12-02"},
+			wantLocal: 1,
+			wantReady: 1,
+		},
+		{ // test that existing counters and ready files are not uploaded if telemetry was recently enabled.
+			name:          "oktoupload",
+			today:         "2019-12-10",
+			date:          "2019-12-09",
+			begins:        "2019-12-02",
+			ends:          "2019-12-09",
+			readys:        []string{"2019-12-07"},
+			wantLocal:     1,
+			wantReady:     1, // ready report is before the first upload time
+			wantUploadeds: 1, // ...but the new report is uploaded
+		},
+		{ // test that existing counters and ready files are not uploaded if telemetry was recently enabled.
+			name:          "uploadnewreport",
+			today:         "2019-12-14",
+			date:          "2019-12-12",
+			begins:        "2019-12-04",
+			ends:          "2019-12-12",
+			readys:        []string{"2019-12-13"},
+			wantLocal:     1,
+			wantUploadeds: 2, // ready report was uploaded
+		},
 		{ // test that an old countfile is removed and no reports generated
 			name:   "oldcountfile",
 			today:  today,
@@ -106,7 +137,8 @@ func TestDates(t *testing.T) {
 			wantReady:  1, // existing premature ready file
 		},
 	}
-	used := make(map[string]string) // dates have to be different, names should be
+	// Used maps ensures that test cases are for distinct dates.
+	used := make(map[string]string)
 	for _, tx := range tests {
 		if used[tx.name] != "" || used[tx.date] != "" {
 			t.Errorf("test %s reusing name or date. name:%s, date:%s",
@@ -172,17 +204,23 @@ func createUploadConfig(cfilename string) (*telemetry.UploadConfig, string) {
 	return &ans, strings.Join(flds[:4], "-") + "-"
 }
 
-// a single test
+// Test is a single test.
+//
+// All dates are in YYYY-MM-DD format.
 type Test struct {
-	name  string
-	today string
+	name  string // the test name; only used for descriptive output
+	today string // the date of the fake upload
 	// count file
-	date         string // in the name
-	begins, ends string // in the metadata
-	// reports in the local dir (entries are YYYY-MM-DD)
+	date         string // the date in of the upload file name; must be unique among tests
+	begins, ends string // the begin and end date stored in the counter metadata
+
+	// Dates of load reports in the local dir.
 	locals []string
+
+	// Dates of upload reports in the local dir.
 	readys []string
-	// already uploaded
+
+	// Dates of reports already uploaded.
 	uploads []string
 
 	// number of expected results

internal/upload/findwork.go

@@ -8,6 +8,8 @@ import (
 	"os"
 	"path/filepath"
 	"strings"
+
+	it "golang.org/x/telemetry/internal/telemetry"
 )
 
 // files to handle
@@ -29,6 +31,9 @@ func findWork(localdir, uploaddir string) work {
 		logger.Printf("could not read %s, progress impossible (%v)", localdir, err)
 		return ans
 	}
+
+	mode, asof := it.Mode()
+
 	// count files end in .v1.count
 	// reports end in .json. If they are not to be uploaded they
 	// start with local.
@@ -41,10 +46,29 @@ func findWork(localdir, uploaddir string) work {
 			ans.countfiles = append(ans.countfiles, fname)
 		} else if strings.HasPrefix(fi.Name(), "local.") {
 			// skip
-		} else if strings.HasSuffix(fi.Name(), ".json") {
-			ans.readyfiles = append(ans.readyfiles, filepath.Join(localdir, fi.Name()))
+		} else if strings.HasSuffix(fi.Name(), ".json") && mode == "on" {
+			// Collect reports that are ready for upload.
+			reportDate := uploadReportDate(fi.Name())
+			if !asof.IsZero() && !reportDate.IsZero() {
+				// If both the mode asof date and the report date are present, do the
+				// right thing...
+				//
+				// (see https://github.com/golang/go/issues/63142#issuecomment-1734025130)
+				if asof.AddDate(0, 0, 7).Before(reportDate) {
+					ans.readyfiles = append(ans.readyfiles, filepath.Join(localdir, fi.Name()))
+				}
+			} else {
+				// ...otherwise fall back on the old behavior of uploading all
+				// unuploaded files.
+				//
+				// TODO(rfindley): invert this logic following more testing. We
+				// should only upload if we know both the asof date and the report
+				// date, and they are acceptable.
+				ans.readyfiles = append(ans.readyfiles, filepath.Join(localdir, fi.Name()))
+			}
 		}
 	}
+
 	fis, err = os.ReadDir(uploaddir)
 	if err != nil {
 		os.MkdirAll(uploaddir, 0777)

internal/upload/first_test.go

@@ -15,7 +15,7 @@ import (
 // In practice this test runs last, so is somewhat superfluous,
 // but it also checks that uploads and reads from the channel are matched
 func TestSimpleServer(t *testing.T) {
-	setup(t)
+	setup(t, "2023-01-01")
 	defer restore()
 	url := uploadURL
 	resp, err := http.Post(url+"/foo", "text/plain", strings.NewReader("hello"))

internal/upload/reports.go

@@ -13,6 +13,7 @@ import (
 	"os"
 	"path/filepath"
 	"strings"
+	"time"
 
 	"golang.org/x/telemetry"
 	"golang.org/x/telemetry/internal/configstore"
@@ -110,12 +111,26 @@ func createReport(date string, files []string, lastWeek string) (string, error)
 		configVersion = v
 	}
 	uploadOK := true
-	if uploadConfig == nil || it.Mode() != "on" {
+	mode, asof := it.Mode()
+	if uploadConfig == nil || mode != "on" {
 		uploadOK = false // no config, nothing to upload
 	}
 	if tooOld(date) {
 		uploadOK = false
 	}
+	if uploadOK && !asof.IsZero() {
+		// If the mode is recorded with an asof date, don't upload if the asof date
+		// is too recent.
+		uploadOK = false
+		t, err := time.Parse("2006-01-02", date)
+		if err == nil {
+			if asof.AddDate(0, 0, 7).Before(t) {
+				uploadOK = true
+			}
+		} else {
+			logger.Printf("parsing report date: %v", err)
+		}
+	}
 	// should we check that all the x.Meta are consistent for GOOS, GOARCH, etc?
 	report := &telemetry.Report{
 		Config:   configVersion,