Unable to add custom dimension to metrics

[Stono]

Bug description
Hello,
I'm following the documentation in https://istio.io/latest/docs/tasks/observability/metrics/customize-metrics to attempt to add a dimension to istio_requests_total on the outbound sidecar, that indicates if the request was sampled.

I have added the following block to our installer options:

    telemetry:
      enabled: true
      v2:
        enabled: true
        prometheus:
          configOverride:
            outboundSidecar:
              debug: false
              stat_prefix: istio
              metrics:
              - name: requests_total
                dimensions:
                  sampled: request.headers.x-b3-sampled

Which gives a complete set of options (merging with our already existing configuration to remove some cardinality):

    telemetry:
      enabled: true
      v2:
        enabled: true
        prometheus:
          configOverride:
            outboundSidecar:
              debug: false
              stat_prefix: istio
              metrics:
              - name: requests_total
                dimensions:
                  sampled: request.headers.x-b3-sampled
              - tags_to_remove:
                - destination_canonical_service
                - source_canonical_service
                - destination_principal
                - source_principal
                - connection_security_policy
                - grpc_response_status
                - source_version
                - destination_version
                - request_protocol
                - source_canonical_revision
                - destination_canonical_revision
                - source_cluster
                - destination_cluster
                - destination_app
              - name: request_duration_milliseconds
                tags_to_remove:
                - response_code
                - response_flags
                - source_cluster
                - destination_cluster
              - name: request_bytes
                tags_to_remove:
                - response_code
                - response_flags
                - source_cluster
                - destination_cluster
              - name: response_bytes
                tags_to_remove:
                - response_code
                - response_flags
                - source_cluster
                - destination_cluster

This appears to modify the EnvoyFitler as expected:

apiVersion: networking.istio.io/v1alpha3
kind: EnvoyFilter
metadata:
  name: stats-filter-1.10
  namespace: istio-system
  labels:
    istio.io/rev: default
    helm-platform-istio: 1.10.2
spec:
  configPatches:
  - applyTo: HTTP_FILTER
    match:
      context: SIDECAR_OUTBOUND
      proxy:
        proxyVersion: "^1\\.10.*"
      listener:
        filterChain:
          filter:
            name: envoy.filters.network.http_connection_manager
            subFilter:
              name: envoy.filters.http.router
    patch:
      operation: INSERT_BEFORE
      value:
        name: istio.stats
        typed_config:
          "@type": type.googleapis.com/udpa.type.v1.TypedStruct
          type_url: type.googleapis.com/envoy.extensions.filters.http.wasm.v3.Wasm
          value:
            config:
              root_id: stats_outbound
              configuration:
                "@type": type.googleapis.com/google.protobuf.StringValue
                value: '{"debug":false,"metrics":[{"dimensions":{"sampled":"request.headers.x-b3-sampled"},"name":"requests_total"},{"tags_to_remove":["destination_canonical_service","source_canonical_service","destination_principal","source_principal","connection_security_policy","grpc_response_status","source_version","destination_version","request_protocol","source_canonical_revision","destination_canonical_revision","source_cluster","destination_cluster","destination_app"]},{"name":"request_duration_milliseconds","tags_to_remove":["response_code","response_flags","source_cluster","destination_cluster"]},{"name":"request_bytes","tags_to_remove":["response_code","response_flags","source_cluster","destination_cluster"]},{"name":"response_bytes","tags_to_remove":["response_code","response_flags","source_cluster","destination_cluster"]}],"stat_prefix":"istio"}

                  '
              vm_config:
                vm_id: stats_outbound
                runtime: envoy.wasm.runtime.null
                code:
                  local:
                    inline_string: envoy.wasm.stats

However when the updated EnvoyFilter is applied, we lose metrics entirely (istio_requests_total for all sidecars stops working).

I was speaking to @douglas-reid ; and he said to check the istio-proxy logs, however there is nothing in them:

❯ k logs istio-test-app-1-69d7644787-fwbb5 -c istio-proxy
{"timestamp":"2021-07-06T16:30:05+00:00","level":"info","module":"pilot-agent-agent","message":"Starting custom autotrader pilot-agent wrapper..."}
{"timestamp":"2021-07-06T16:30:05+00:00","level":"info","module":"pilot-agent-agent","message":"Pilot-agent args: proxy"}
{"timestamp":"2021-07-06T16:30:05+00:00","level":"info","module":"pilot-agent-agent","message":"Pilot agent started with pid: 9"}
{"level":"info","time":"2021-07-06T16:30:05.494489Z","scope":"citadelclient","msg":"Citadel client using custom root cert: istiod.istio-system.svc:15012"}
{"level":"info","time":"2021-07-06T16:30:05.547565Z","scope":"ads","msg":"All caches have been synced up in 58.411564ms, marking server ready"}
{"level":"info","time":"2021-07-06T16:30:05.560215Z","scope":"sds","msg":"SDS server for workload certificates started, listening on \"./etc/istio/proxy/SDS\""}
{"level":"info","time":"2021-07-06T16:30:05.560302Z","scope":"sds","msg":"Start SDS grpc server"}
{"level":"info","time":"2021-07-06T16:30:05.560394Z","scope":"xdsproxy","msg":"Initializing with upstream address \"istiod.istio-system.svc:15012\" and cluster \"Kubernetes\""}
{"level":"info","time":"2021-07-06T16:30:05.818916Z","scope":"xdsproxy","msg":"connected to upstream XDS server: istiod.istio-system.svc:15012"}
{"level":"info","time":"2021-07-06T16:30:05.828389Z","scope":"cache","msg":"generated new workload certificate","latency":280145920,"ttl":86399171622729}
{"level":"info","time":"2021-07-06T16:30:05.828457Z","scope":"cache","msg":"Root cert has changed, start rotating root cert"}
{"level":"info","time":"2021-07-06T16:30:05.828479Z","scope":"ads","msg":"XDS: Incremental Pushing:0 ConnectedEndpoints:0 Version:"}
{"level":"info","time":"2021-07-06T16:30:05.828519Z","scope":"cache","msg":"returned workload trust anchor from cache","ttl":86399171482242}
{"level":"info","time":"2021-07-06T16:30:05.868540Z","scope":"ads","msg":"ADS: new connection for node:sidecar~10.206.1.87~istio-test-app-1-69d7644787-fwbb5.istio-test-app-1~istio-test-app-1.svc.cluster.local-1"}
{"level":"info","time":"2021-07-06T16:30:05.868624Z","scope":"cache","msg":"returned workload trust anchor from cache","ttl":86399131379030}
{"level":"info","time":"2021-07-06T16:30:05.868819Z","scope":"ads","msg":"ADS: new connection for node:sidecar~10.206.1.87~istio-test-app-1-69d7644787-fwbb5.istio-test-app-1~istio-test-app-1.svc.cluster.local-2"}
{"level":"info","time":"2021-07-06T16:30:05.868913Z","scope":"cache","msg":"returned workload certificate from cache","ttl":86399131090167}
{"level":"info","time":"2021-07-06T16:30:05.869044Z","scope":"sds","msg":"SDS: PUSH","resource":"ROOTCA"}
{"level":"info","time":"2021-07-06T16:30:05.869059Z","scope":"sds","msg":"SDS: PUSH","resource":"default"}

So it seems to fail silently.

[ ] Docs
[ ] Installation
[ ] Networking
[ ] Performance and Scalability
[x] Extensions and Telemetry
[ ] Security
[ ] Test and Release
[x] User Experience
[ ] Developer Infrastructure
[ ] Upgrade

Expected behavior
Either additional dimensions to work, or, output an error why

Steps to reproduce the bug
As above

Version (include the output of istioctl version --remote and kubectl version --short and helm version --short if you used Helm)
1.10.2

How was Istio installed?

Environment where the bug was observed (cloud vendor, OS, etc)

Additionally, please consider running istioctl bug-report and attach the generated cluster-state tarball to this issue.
Refer cluster state archive for more details.

[bianpengyuan]

Have you added sampled into the extraStatTags in ProxyConfig?

[Stono]

@bianpengyuan no not yet, because i was wanting to use the per-pod annotation instead, therefore "turning this on" I believed to be two phases:

1. The global stats EnvoyFilter (which should be a no-op on existing behaviour)
2. The extra stats annotation on the workloads that i want it on

I don't expect all metrics to stop working when enabling one additional dimension to the EnvoyFilter, before step #2.

[Stono]

Just out of curiosity I added the meshConfig version of extraStatsTags, and observed the same thing, all metrics simply stop working:

[Stono]

So I decided to look at one of the envoys directly with a port-forward and observed this in the metrics:

# TYPE envoy_sampled___unknown___istio_requests_total counter
envoy_sampled___unknown___istio_requests_total{response_code="200",reporter="source",source_workload="istio-test-app-1",source_workload_namespace="istio-test-app-1",source_app="istio-test-app-1",destination_workload="istio-test-app-2",destination_workload_namespace="istio-test-app-2",destination_service="app.istio-test-app-2.svc.cluster.local",destination_service_name="app",destination_service_namespace="istio-test-app-2",response_flags="-"} 3392
envoy_sampled___unknown___istio_requests_total{response_code="200",reporter="source",source_workload="istio-test-app-1",source_workload_namespace="istio-test-app-1",source_app="istio-test-app-1",destination_workload="istio-test-app-3",destination_workload_namespace="istio-test-app-3",destination_service="app.istio-test-app-3.svc.cluster.local",destination_service_name="app",destination_service_namespace="istio-test-app-3",response_flags="-"} 1665

[bianpengyuan]

Yeah, you will need to restart workload. It is part of bootstrap configuration.

[Stono]

But surely existing metrics shouldn't break until we've restarted it, otherwise there would be no way to roll it out without cluster wide outage of metrics until all workloads are restarted (simply not feasible at any sort of scale?)

[bianpengyuan]

But surely existing metrics shouldn't break until we've restarted it, otherwise there would be no way to roll it out without cluster wide outage of metrics until all workloads are restarted?

Yeah you will need to make sure the new tag is picked up by all proxies, then update the metric configuration. Unfortunately this is complicated because stats configuration is part of envoy's bootstrap..

[Stono]

Right so I restarted the workload and the metrics for that single pod worked when using meshConfig.defaultConfig. It doesn't work using the annotation for me at all.

So basically this is impossible to roll out without downtime for our observability? I personally can't have metrics failing until I've restarted every workload when I have 400+, and have a business that depends on that data being up to date and accurate.

That's pretty painful for people who want to start using this feature in existing deployments (it's not even called out in the documentation). Surely there's got to be a way around turning it on without causing the outage to metrics. For example, couldn't these changes (to the dimensions field in EnvoyFilter) only take affect once a workload restarts for example (so ignored by existing proxies?)?

[douglas-reid]

@bianpengyuan @kyessenov shouldn't we at least have something in the logs when we get in situations like this? any ideas why there were no logs?

[douglas-reid]

Right so I restarted the workload and the metrics for that single pod worked when using meshConfig.defaultConfig. It doesn't work using the annotation for me at all.

So basically this is impossible to roll out without downtime for our observability? I personally can't have metrics failing until I've restarted every workload when I have 400+, and have a business that depends on that data being up to date and accurate.

That's pretty painful for people who want to start using this feature in existing deployments (it's not even called out in the documentation). Surely there's got to be a way around turning it on without causing the outage to metrics. For example, couldn't these changes (to the dimensions field in EnvoyFilter) only take affect once a workload restarts for example (so ignored by existing proxies?)?

@howardjohn @kyessenov do you think we could have validation logic that checks new dimensions against the effective set to warn of these situations? also, does Envoy expose the known stats tags for inspection by extensions? could we be smarter in the stats extension?

[kyessenov]

With telemetry API and pilot keeping track of which stat tags have been applied, it should be possible to gradually roll it out.
It's not possible to do it internally in Envoy yet.

[howardjohn]

I think we would need to return the stats tag config in the node metadata as well so that Istiod knows what has been applied as well?

[kyessenov]

@howardjohn That would work but it feels awkward to place internal details into node metadata.