exporters/stdout TestStdoutTimestamp test failure

[MrAlias]

This test seems to consistently be failing for Windows testing using Go 1.14 and 1.15:

https://github.com/open-telemetry/opentelemetry-go/runs/1962753557?check_suite_focus=true

go test -timeout 30s -short ./exporters/stdout/...
--- FAIL: TestStdoutTimestamp (0.04s)
    metric_test.go:122: 
        	Error Trace:	metric_test.go:122
        	Error:      	Should be true
        	Test:       	TestStdoutTimestamp
FAIL
FAIL	go.opentelemetry.io/otel/exporters/stdout	0.775s
FAIL
mingw32-make: *** [Makefile:100: test] Error 123

Looking at the test ...

opentelemetry-go/exporters/stdout/metric_test.go

Lines 78 to 124 in b94cd4b

	func TestStdoutTimestamp(t *testing.T) {
	var buf bytes.Buffer
	exporter, err := stdout.NewExporter(
	stdout.WithWriter(&buf),
	)
	if err != nil {
	t.Fatal("Invalid config: ", err)
	}
	before := time.Now()
	checkpointSet := metrictest.NewCheckpointSet(testResource)
	ctx := context.Background()
	desc := metric.NewDescriptor("test.name", metric.ValueObserverInstrumentKind, number.Int64Kind)
	lvagg, ckpt := metrictest.Unslice2(lastvalue.New(2))
	aggregatortest.CheckedUpdate(t, lvagg, number.NewInt64Number(321), &desc)
	require.NoError(t, lvagg.SynchronizedMove(ckpt, &desc))
	checkpointSet.Add(&desc, ckpt)
	if err := exporter.Export(ctx, checkpointSet); err != nil {
	t.Fatal("Unexpected export error: ", err)
	}
	after := time.Now()
	var printed []interface{}
	if err := json.Unmarshal(buf.Bytes(), &printed); err != nil {
	t.Fatal("JSON parse error: ", err)
	}
	require.Len(t, printed, 1)
	lastValue, ok := printed[0].(map[string]interface{})
	require.True(t, ok, "last value format")
	require.Contains(t, lastValue, "Timestamp")
	lastValueTS := lastValue["Timestamp"].(string)
	lastValueTimestamp, err := time.Parse(time.RFC3339Nano, lastValueTS)
	if err != nil {
	t.Fatal("JSON parse error: ", lastValueTS, ": ", err)
	}
	assert.True(t, lastValueTimestamp.After(before))
	assert.True(t, lastValueTimestamp.Before(after))
	}

Proposals

• It is testing a "before" time is before a measured timestamp without ensuring there is a delay of time. We should add a small artificial duration to ensure this test succeeds.
• We can remove the check of the before/after timestamp. I'm not sure these are actually adding value. I think we need to verify that a timestamp is returned, but I'm not sure it is the exporters responsibility to ensure the monotonicity of the timestamps (rather that is the metrics pipeline itself).

[punya]

We're running into the same issue in #1559 too: tests flaking because they assume that a nonzero amount of time elapses. There we decided to add artificial delays in the test to make the behavior predictable.

[MrAlias]

We're running into the same issue in #1559 too: tests flaking because they assume that a nonzero amount of time elapses. There we decided to add artificial delays in the test to make the behavior predictable.

Cool, sounds like we are going to be consistent in a solution 👍. I've taken the same approach in the linked PR.