The start time must be before the end time for the non-gauge metric

zargarpur commented 4 years ago

What version of the Exporter are you using?

contrib.go.opencensus.io/exporter/stackdriver => contrib.go.opencensus.io/exporter/stackdriver v0.12.9-0.20191108183826-59d068f8d8ff

What version of OpenCensus are you using?

go.opencensus.io => go.opencensus.io v0.22.1

What version of Go are you using?

go version go1.14.2 linux/amd64

What did you do?

We have that count metric here https://github.com/google/knative-gcp/blob/d0a452483985c0f1d775efa2ea54fddaed2ed107/pkg/metrics/ingress_reporter.go#L59

Invoked here https://github.com/google/knative-gcp/blob/d0a452483985c0f1d775efa2ea54fddaed2ed107/pkg/metrics/ingress_reporter.go#L103

And we're seeing this error occasionally in our E2E tests that prevents our metrics from being uploaded

default-brokercell-ingress-594cd99c77-57gk6 ingress 2020/06/12 20:48:48 Failed to export to Stackdriver: rpc error: code = InvalidArgument desc = Field timeSeries[1].points[0].interval.start_time had an invalid value of "2020-06-12T13:48:47.794571-07:00": The start time must be before the end time (2020-06-12T13:48:47.794571-07:00) for the non-gauge metric 'knative.dev/internal/eventing/broker/event_count'.

If possible, provide a recipe for reproducing the error. We have a continuous E2E test runs that occasionally run into this issue which is exercising the code path above https://testgrid.knative.dev/knative-gcp#continuous&include-filter-by-regex=TestGCPBrokerMetrics

What did you expect to see?

Metrics consistently uploaded to Stackdriver without this error

What did you see instead?

This error message

default-brokercell-ingress-594cd99c77-57gk6 ingress 2020/06/12 20:48:48 Failed to export to Stackdriver: rpc error: code = InvalidArgument desc = Field timeSeries[1].points[0].interval.start_time had an invalid value of "2020-06-12T13:48:47.794571-07:00": The start time must be before the end time (2020-06-12T13:48:47.794571-07:00) for the non-gauge metric 'knative.dev/internal/eventing/broker/event_count'.

Additional context

Add any other context about the problem here.

zargarpur commented 4 years ago

/assign @nilebox

nilebox commented 4 years ago

Looks like start and end times are the same, and Stackdriver rejects such counter?

AFAICT the start and end times are coming from the view.Data structure: https://github.com/census-ecosystem/opencensus-go-exporter-stackdriver/blob/1905f4643248273f1ed512fdf1b6473d2e4445b4/stats.go#L249

They are set in https://github.com/census-instrumentation/opencensus-go/blob/1901b56b9515b0c34f5d25a5bce982dfc543d64b/stats/view/worker.go#L352-L353

And there is a condition under which both Start and End will be set to "now": https://github.com/census-instrumentation/opencensus-go/blob/1901b56b9515b0c34f5d25a5bce982dfc543d64b/stats/view/worker.go#L346-L349

This is likely what is causing the problem for you.

Potential ways to fix the issue:

In opencensus-go: prevent setting both start and end times to "now" for non-gauges
In opencensus-go-exporter-stackdriver: Implement some hack to add a nanosecond to make start and end times different - this may break the accuracy though
In opencensus-go-exporter-stackdriver: Drop views which have equal start and end times - this leads to data loss

Not sure if there is a good way to fix that.

/cc @james-bebbington @rghetia