"MetricValueSet has value with duplicated signature" error response when submitting metrics

[chellstrom]

My company uses the Cloud Endpoints framework on App Engine. Starting on July 6, 2020, we noticed that this error message appeared in the logs of every endpoint call, and we could no longer see metrics for the endpoints on the Google Cloud console:

reportRequest: <ReportRequest
 operations: [<Operation
 consumerId: u'<omitted>'
 endTime: u'2020-07-20T23:45:48.592065Z'
 importance: ImportanceValueValuesEnum(LOW, 0)
 labels: <LabelsValue
 additionalProperties: [<AdditionalProperty
 key: '/status_code'
 value: u'0'>, <AdditionalProperty
 key: '/protocol'
 value: u'HTTP'>, <AdditionalProperty
 key: '/response_code'
 value: u'200'>, <AdditionalProperty
 key: '/response_code_class'
 value: u'2xx'>, <AdditionalProperty
 key: 'servicecontrol.googleapis.com/user_agent'
 value: u'ESP'>, <AdditionalProperty
 key: 'serviceruntime.googleapis.com/api_method'
 value: u'<omitted>'>, <AdditionalProperty
 key: 'serviceruntime.googleapis.com/consumer_project'
 value: u'<omitted>'>, <AdditionalProperty
 key: 'servicecontrol.googleapis.com/platform'
 value: u'GAE Standard'>, <AdditionalProperty
 key: 'cloud.googleapis.com/location'
 value: u'global'>, <AdditionalProperty
 key: 'servicecontrol.googleapis.com/service_agent'
 value: u'EF_PYTHON/1.11.0'>, <AdditionalProperty
 key: '/error_type'
 value: u'2xx'>]>
 logEntries: [<LogEntry
 name: u'endpoints_log'
 severity: SeverityValueValuesEnum(INFO, 2)
 structPayload: <StructPayloadValue
 additionalProperties: [<AdditionalProperty
 key: u'api_method'
 value: <JsonValue
 string_value: u'<omitted>'>>, <AdditionalProperty
 key: u'http_response_code'
 value: <JsonValue
 integer_value: 200>>, <AdditionalProperty
 key: u'producer_project_id'
 value: <JsonValue
 string_value: u'<omitted>'>>, <AdditionalProperty
 key: u'url'
 value: <JsonValue
 array_value: <JsonArray
 entries: [<JsonValue
 string_value: u'https'>, <JsonValue
 string_value: u'<omitted>'>, <JsonValue
 string_value: u'<omitted>'>, <JsonValue
 string_value: u''>, <JsonValue
 string_value: u'<omitted>'>, <JsonValue
 string_value: u''>]>>>, <AdditionalProperty
 key: u'timestamp'
 value: <JsonValue
 double_value: 1595288748.0>>, <AdditionalProperty
 key: u'request_latency_in_ms'
 value: <JsonValue
 double_value: 647.494>>, <AdditionalProperty
 key: u'http_method'
 value: <JsonValue
 string_value: u'GET'>>, <AdditionalProperty
 key: u'location'
 value: <JsonValue
 string_value: u'global'>>, <AdditionalProperty
 key: u'response_size'
 value: <JsonValue
 integer_value: 2442>>]>
 timestamp: u'2020-07-20T23:45:48.59435Z'>]
 metricValueSets: [<MetricValueSet
 metricName: u'serviceruntime.googleapis.com/api/consumer/backend_latencies'
 metricValues: [<MetricValue
 distributionValue: <Distribution
 bucketCounts: [0, 0, 0, 0, 0, 0, 1, 0, 0, 0]
 count: 1
 exponentialBuckets: <ExponentialBuckets
 growthFactor: 10.0
 numFiniteBuckets: 8
 scale: 1e-06>
 maximum: 0.545749
 mean: 0.545749
 minimum: 0.545749
 sumOfSquaredDeviation: 0.0>>]>, <MetricValueSet
 metricName: u'serviceruntime.googleapis.com/api/consumer/request_count'
 metricValues: [<MetricValue
 int64Value: 1>]>, <MetricValueSet
 metricName: u'serviceruntime.googleapis.com/api/consumer/request_overhead_latencies'
 metricValues: [<MetricValue
 distributionValue: <Distribution
 bucketCounts: [0, 0, 0, 0, 0, 0, 1, 0, 0, 0]
 count: 1
 exponentialBuckets: <ExponentialBuckets
 growthFactor: 10.0
 numFiniteBuckets: 8
 scale: 1e-06>
 maximum: 0.101745
 mean: 0.101745
 minimum: 0.101745
 sumOfSquaredDeviation: 0.0>>]>, <MetricValueSet
 metricName: u'serviceruntime.googleapis.com/api/consumer/response_sizes'
 metricValues: [<MetricValue
 distributionValue: <Distribution
 bucketCounts: [0, 0, 0, 0, 1, 0, 0, 0, 0, 0]
 count: 1
 exponentialBuckets: <ExponentialBuckets
 growthFactor: 10.0
 numFiniteBuckets: 8
 scale: 1.0>
 maximum: 2442.0
 mean: 2442.0
 minimum: 2442.0
 sumOfSquaredDeviation: 0.0>>]>, <MetricValueSet
 metricName: u'serviceruntime.googleapis.com/api/consumer/total_latencies'
 metricValues: [<MetricValue
 distributionValue: <Distribution
 bucketCounts: [0, 0, 0, 0, 0, 0, 1, 0, 0, 0]
 count: 1
 exponentialBuckets: <ExponentialBuckets
 growthFactor: 10.0
 numFiniteBuckets: 8
 scale: 1e-06>
 maximum: 0.647494
 mean: 0.647494
 minimum: 0.647494
 sumOfSquaredDeviation: 0.0>>]>, <MetricValueSet
 metricName: u'serviceruntime.googleapis.com/api/producer/backend_latencies'
 metricValues: [<MetricValue
 distributionValue: <Distribution
 bucketCounts: [0, 0, 0, 0, 0, 0, 1, 0, 0, 0]
 count: 1
 exponentialBuckets: <ExponentialBuckets
 growthFactor: 10.0
 numFiniteBuckets: 8
 scale: 1e-06>
 maximum: 0.545749
 mean: 0.545749
 minimum: 0.545749
 sumOfSquaredDeviation: 0.0>>]>, <MetricValueSet
 metricName: u'serviceruntime.googleapis.com/api/producer/by_consumer/backend_latencies'
 metricValues: [<MetricValue
 distributionValue: <Distribution
 bucketCounts: [0, 0, 0, 0, 0, 0, 1, 0, 0, 0]
 count: 1
 exponentialBuckets: <ExponentialBuckets
 growthFactor: 10.0
 numFiniteBuckets: 8
 scale: 1e-06>
 maximum: 0.545749
 mean: 0.545749
 minimum: 0.545749
 sumOfSquaredDeviation: 0.0>>]>, <MetricValueSet
 metricName: u'serviceruntime.googleapis.com/api/producer/by_consumer/request_count'
 metricValues: [<MetricValue
 int64Value: 1>]>, <MetricValueSet
 metricName: u'serviceruntime.googleapis.com/api/producer/by_consumer/request_overhead_latencies'
 metricValues: [<MetricValue
 distributionValue: <Distribution
 bucketCounts: [0, 0, 0, 0, 0, 0, 1, 0, 0, 0]
 count: 1
 exponentialBuckets: <ExponentialBuckets
 growthFactor: 10.0
 numFiniteBuckets: 8
 scale: 1e-06>
 maximum: 0.101745
 mean: 0.101745
 minimum: 0.101745
 sumOfSquaredDeviation: 0.0>>]>, <MetricValueSet
 metricName: u'serviceruntime.googleapis.com/api/producer/by_consumer/response_sizes'
 metricValues: [<MetricValue
 distributionValue: <Distribution
 bucketCounts: [0, 0, 0, 0, 1, 0, 0, 0, 0, 0]
 count: 1
 exponentialBuckets: <ExponentialBuckets
 growthFactor: 10.0
 numFiniteBuckets: 8
 scale: 1.0>
 maximum: 2442.0
 mean: 2442.0
 minimum: 2442.0
 sumOfSquaredDeviation: 0.0>>]>, <MetricValueSet
 metricName: u'serviceruntime.googleapis.com/api/producer/by_consumer/total_latencies'
 metricValues: [<MetricValue
 distributionValue: <Distribution
 bucketCounts: [0, 0, 0, 0, 0, 0, 1, 0, 0, 0]
 count: 1
 exponentialBuckets: <ExponentialBuckets
 growthFactor: 10.0
 numFiniteBuckets: 8
 scale: 1e-06>
 maximum: 0.647494
 mean: 0.647494
 minimum: 0.647494
 sumOfSquaredDeviation: 0.0>>]>, <MetricValueSet
 metricName: u'serviceruntime.googleapis.com/api/producer/request_count'
 metricValues: [<MetricValue
 int64Value: 1>]>, <MetricValueSet
 metricName: u'serviceruntime.googleapis.com/api/producer/request_overhead_latencies'
 metricValues: [<MetricValue
 distributionValue: <Distribution
 bucketCounts: [0, 0, 0, 0, 0, 0, 1, 0, 0, 0]
 count: 1
 exponentialBuckets: <ExponentialBuckets
 growthFactor: 10.0
 numFiniteBuckets: 8
 scale: 1e-06>
 maximum: 0.101745
 mean: 0.101745
 minimum: 0.101745
 sumOfSquaredDeviation: 0.0>>]>, <MetricValueSet
 metricName: u'serviceruntime.googleapis.com/api/producer/response_sizes'
 metricValues: [<MetricValue
 distributionValue: <Distribution
 bucketCounts: [0, 0, 0, 0, 1, 0, 0, 0, 0, 0]
 count: 1
 exponentialBuckets: <ExponentialBuckets
 growthFactor: 10.0
 numFiniteBuckets: 8
 scale: 1.0>
 maximum: 2442.0
 mean: 2442.0
 minimum: 2442.0
 sumOfSquaredDeviation: 0.0>>]>, <MetricValueSet
 metricName: u'serviceruntime.googleapis.com/api/producer/total_latencies'
 metricValues: [<MetricValue
 distributionValue: <Distribution
 bucketCounts: [0, 0, 0, 0, 0, 0, 1, 0, 0, 0]
 count: 1
 exponentialBuckets: <ExponentialBuckets
 growthFactor: 10.0
 numFiniteBuckets: 8
 scale: 1e-06>
 maximum: 0.647494
 mean: 0.647494
 minimum: 0.647494
 sumOfSquaredDeviation: 0.0>>]>]
 operationId: u'e28c394bd46d450388e25f8dcc31e05f'
 operationName: u'<omitted>'
 resourceContainers: []
 startTime: u'2020-07-20T23:45:48.592065Z'>]>
 serviceName: '<omitted>'>
Traceback (most recent call last):
  File "<omitted>/endpoints_management/control/client.py", line 470, in _flush_schedule_report_aggregator
    transport.services.Report(req)
  File "<omitted>/endpoints_management/gen/servicecontrol_v1_client.py", line 237, in Report
    config, request, global_params=global_params)
  File "<omitted>/apitools/base/py/base_api.py", line 730, in _RunMethod
    return self.ProcessHttpResponse(method_config, http_response, request)
  File "<omitted>/apitools/base/py/base_api.py", line 736, in ProcessHttpResponse
    self.__ProcessHttpResponse(method_config, http_response, request))
  File "<omitted>/apitools/base/py/base_api.py", line 603, in __ProcessHttpResponse
    http_response, method_config=method_config, request=request)
HttpBadRequestError: HttpError accessing <https://servicecontrol.googleapis.com/v1/services/<omitted>:report?alt=json>: response: <{'status': '400', 'content-length': '677', 'x-xss-protection': '0', 'x-content-type-options': 'nosniff', 'transfer-encoding': 'chunked', 'vary': 'Origin, X-Origin, Referer', 'server': 'ESF', '-content-encoding': 'gzip', 'cache-control': 'private', 'date': 'Mon, 20 Jul 2020 23:45:52 GMT', 'x-frame-options': 'SAMEORIGIN', 'content-type': 'application/json; charset=UTF-8'}>, content <{
  "error": {
    "code": 400,
    "message": "MetricValueSet has value with duplicated signature: metric_name: \"serviceruntime.googleapis.com/api/request_latencies_backend\"\nmetric_values {\n  distribution_value {\n    count: 1\n    mean: 0.545749\n    minimum: 0.545749\n    maximum: 0.545749\n    bucket_counts: 0\n    bucket_counts: 0\n    bucket_counts: 0\n    bucket_counts: 0\n    bucket_counts: 0\n    bucket_counts: 0\n    bucket_counts: 1\n    bucket_counts: 0\n    bucket_counts: 0\n    bucket_counts: 0\n    exponential_buckets {\n      num_finite_buckets: 8\n      growth_factor: 10\n      scale: 1e-06\n    }\n  }\n}\n",
    "status": "INVALID_ARGUMENT"
  }
}
>

The message complains about a metric called serviceruntime.googleapis.com/api/request_latencies_backend having a duplicate signature, but the library does not send a metric with that name.

I did notice the library sends 3 metrics related to backend latency, that are computed using the same function:

• serviceruntime.googleapis.com/api/consumer/backend_latencies
• serviceruntime.googleapis.com/api/producer/backend_latencies
• serviceruntime.googleapis.com/api/producer/by_consumer/backend_latencies

I made a guess that Google was mapping these three metrics to serviceruntime.googleapis.com/api/request_latencies_backend, and tried monkeypatching the library to only send one of the three. That fixed the issue and the library was able to send metrics again.

Can anyone confirm if this is a new bug with the library caused by some change Google made internally?