search

GoogleCloudPlatform / k8s-stackdriver

Apache License 2.0
390 stars 211 forks source link

Tracing custom-metrics-stackdriver-adapter trace logging enabled #640

Open kallangerard opened 6 months ago

kallangerard commented 6 months ago

It appears that in gcr.io/gke-release/custom-metrics-stackdriver-adapter:v0.14.2-gke.0, traces are enabled and logging to stdout.

We're using the manifests from this commit reference https://github.com/GoogleCloudPlatform/k8s-stackdriver/blob/303ec9ad1ca8d09e2ea93a7ff2ce3aea7a9f8a97/custom-metrics-stackdriver-adapter/deploy/production/adapter.yaml,

We end up with an enormous amount of logs like below:

I0205 06:40:24.007357       1 trace.go:205] Trace[1008513964]: "List" url:/apis/external.metrics.k8s.io/v1beta1/namespaces/default/pubsub.googleapis.com|subscription|num_undelivered_messages,user-agent:vpa-recommender/v0.0.0 (linux/amd64) kubernetes/$Format/metrics-horizontal-pod-autoscaler,audit-id:<REDACTED>,client:<REDACTED>,accept:application/vnd.kubernetes.protobuf, */*,protocol:HTTP/2.0 (05-Feb-2024 06:40:23.298) (total time: 709ms):
Trace[1008513964]: ---"Listing from storage done" 709ms (06:40:24.007)
Trace[1008513964]: [709.130634ms] [709.130634ms] END
I0205 06:40:26.383958       1 trace.go:205] Trace[15241325]: "List" url:/apis/external.metrics.k8s.io/v1beta1/namespaces/default/pubsub.googleapis.com|subscription|oldest_unacked_message_age,user-agent:vpa-recommender/v0.0.0 (linux/amd64) kubernetes/$Format/metrics-horizontal-pod-autoscaler,audit-id:<REDACTED>,client:<REDACTED>,accept:application/vnd.kubernetes.protobuf, */*,protocol:HTTP/2.0 (05-Feb-2024 06:40:25.687) (total time: 696ms):
Trace[15241325]: ---"Listing from storage done" 696ms (06:40:26.383)
Trace[15241325]: [696.636825ms] [696.636825ms] END
CatherineF-dev commented 5 months ago

qq: does this issue happen starting from v0.14.2-gke.0?

supersam654 commented 5 months ago

I believe this has been going on for a while. We're on gcr.io/gke-release/custom-metrics-stackdriver-adapter:v0.12.2-gke.0 and I see this in our logs:

2024-03-14 08:23:25.409 EDT Trace[939984059]: [801.213144ms] [801.213144ms] END
2024-03-14 08:23:25.607 EDT Trace[911902081]: "SerializeObject" method:GET,url:/apis/custom.metrics.k8s.io/v1beta1,protocol:HTTP/2.0,mediaType:application/json,encoder:{"encoder":"{\"name\":\"json\",\"pretty\":\"false\",\"yaml\":\"false\"}","name":"versioning"} (14-Mar-2024 12:23:20.508) (total time: 5098ms):
2024-03-14 08:23:25.608 EDT Trace[911902081]: [5.098732769s] [5.098732769s] END
CatherineF-dev commented 5 months ago

Thanks for providing this information!

CatherineF-dev commented 5 months ago

/label custom-metrics-stackdriver-adapter

CatherineF-dev commented 5 months ago

btw, @supersam654 did you find high memory issue in v0.12.2-gke.0? If so, try v0.14.2-gke.0 which fixed OOM/high memory issue.

Release note is here https://github.com/GoogleCloudPlatform/k8s-stackdriver/releases/tag/cm-sd-adapter-v0.14.0

CatherineF-dev commented 5 months ago

These traces log are ignorable. Could you try increasing log level by 

        - /adapter
        - --use-new-resource-model=false
        - --v=1

@kallangerard

Trace prints out because whatever action the trace is about takes longer than what the author expects. This is expected for metrics adapter because it fetches data from Cloud Monitoring.