Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Open
kallangerard opened this issue Feb 5, 2024 · 8 comments · May be fixed by #775
Open

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

kallangerard opened this issue Feb 5, 2024 · 8 comments · May be fixed by #775
Labels
custom-metrics-stackdriver-adapter Issues for custom-metrics-stackdriver-adapter

Comments

@kallangerard
Copy link

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
Copy link
Contributor

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

@supersam654
Copy link

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
Copy link
Contributor

Thanks for providing this information!

@CatherineF-dev
Copy link
Contributor

/label custom-metrics-stackdriver-adapter

@CatherineF-dev CatherineF-dev added the custom-metrics-stackdriver-adapter Issues for custom-metrics-stackdriver-adapter label Mar 14, 2024
@CatherineF-dev
Copy link
Contributor

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
Copy link
Contributor

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.

@hermanbanken
Copy link

hermanbanken commented Sep 10, 2024

Since the last version (0.15) this now outputs:

unknown flag: --v

when trying to mute Trace output. I think something broke the klog flag parsing. Maybe the initialisation order is wrong?

Update: the logTrace in k8s-stackdriver/event-exporter/vendor/k8s.io/utils/trace/trace.go matches the trace output (Trace[\d+] and END) perfectly. The issue seems to be that commit f3a96b5ed2c4dd345390001cee3500f4cca3c41c updated to klog v2, which no longer uses init() to register the flags:

# How to use klog
1. Replace imports for "github.com/golang/glog" with "k8s.io/klog/v2"
2. Use klog.InitFlags(nil) explicitly for initializing global flags as we no longer use init() method to register the flags

@hermanbanken
Copy link

Our main problem with this is that the latter go (logs starting with "Trace") end up in stderr, and are therefore classified as "Error" in GCP Cloud Logging, falsely triggering as a problem in our monitoring.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
custom-metrics-stackdriver-adapter Issues for custom-metrics-stackdriver-adapter
Projects
None yet
4 participants