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

A few suspicious logs #1976

Closed
jayunit100 opened this issue Sep 25, 2020 · 11 comments
Closed

A few suspicious logs #1976

jayunit100 opened this issue Sep 25, 2020 · 11 comments
Labels
kind/bug Categorizes issue or PR as related to a bug. lifecycle/stale Denotes an issue or PR has remained open with no activity and has become stale. priority/awaiting-more-evidence Lowest priority. Possibly useful, but not yet enough support to actually get it done.
Milestone

Comments

@jayunit100
Copy link
Contributor

jayunit100 commented Sep 25, 2020

/kind bug

what is the bug

There are suspicious logs in CAPA apiserver and controller manager in the latest capa release . These might be non-issues (conformance tests seem to hum along happily) , but they seem like they might indicate other problems which might relate to managment polling or MHC or ... So just logging my thoughts here.

The three logs im seeing

  • "couldn't parse request url.Values" (APIServer)
  • Failed to watch partial object metadata (KCM)
  • Could not reconcile node routes (KCM)

what steps did you take to reproduce the bug

Spun up a mostly vanilla cluster on capa 0.5.6 using TKG

Details

Inside a see a few suspicious log messages, these may not be important, but seem a little scary.

  1. every 2 seconds or so , i see many label selectors failing. hypothesis: this is from MHC or maybe from nodes doing health checks? The mirror pods from static kubelet manifested kube-controller-manager seems to be the target of some kind of watch, and that watch is failing.
E0925 17:56:58.220906       1 requestinfo.go:214] Couldn't parse request url.Values{"labelSelector":[]string{"name=kube-controller-manager-ip-10-0-4-229.us-west-2.compute.internal"}}: unable to parse requirement: invalid label value: "kube-controller-manager-ip-10-0-4-229.us-west-2.compute.internal": at key: "name": must be no more than 63 characters
E0925 17:57:00.220818       1 requestinfo.go:214] Couldn't parse request url.Values{"labelSelector":[]string{"name=kube-controller-manager-ip-10-0-4-229.us-west-2.compute.internal"}}: unable to parse requirement: invalid label value: "kube-controller-manager-ip-10-0-4-229.us-west-2.compute.internal": at key: "name": must be no more than 63 characters
E0925 17:57:02.220843       1 requestinfo.go:214] Couldn't parse request url.Values{"labelSelector":[]string{"name=kube-controller-manager-ip-10-0-4-229.us-west-2.compute.internal"}}: unable to parse requirement: invalid label value: "kube-controller-manager-ip-10-0-4-229.us-west-2.compute.internal": at key: "name": must be no more than 63 characters
E0925 17:57:04.220892       1 requestinfo.go:214] Couldn't parse request url.Values{"labelSelector":[]string{"name=kube-controller-manager-ip-10-0-4-229.us-west-2.compute.internal"}}: unable to parse requirement: invalid label value: "kube-controller-manager-ip-10-0-4-229.us-west-2.compute.internal": at key: "name": must be no more than 63 characters
E0925 17:57:06.220985       1 requestinfo.go:214] Couldn't parse request url.Values{"labelSelector":[]string{"name=kube-controller-manager-ip-10-0-4-229.us-west-2.compute.internal"}}: unable to parse requirement: invalid label value: "kube-controller-manager-ip-10-0-4-229.us-west-2.compute.internal": at key: "name": must be no more than 63 characters
E0925 17:57:08.220862       1 requestinfo.go:214] Couldn't parse request url.Values{"labelSelector":[]string{"name=kube-controller-manager-ip-10-0-4-229.us-west-2.compute.internal"}}: unable to parse requirement: invalid label value: "kube-controller-manager-ip-10-0-4-229.us-west-2.compute.internal": at key: "name": must be no more than 63 characters
E0925 17:57:10.220818       1 requestinfo.go:214] Couldn't parse request url.Values{"labelSelector":[]string{"name=kube-controller-manager-ip-10-0-4-229.us-west-2.compute.internal"}}: unable to parse requirement: invalid label value: "kube-controller-manager-ip-10-0-4-229.us-west-2.compute.internal": at key: "name": must be no more than 63 characters
E0925 17:57:12.220852       1 requestinfo.go:214] Couldn't parse request url.Values{"labelSelector":[]string{"name=kube-controller-manager-ip-10-0-4-229.us-west-2.compute.internal"}}: unable to parse requirement: invalid label value: "kube-controller-manager-ip-10-0-4-229.us-west-2.compute.internal": at key: "name": must be no more than 63 characters
E0925 17:57:14.221079       1 requestinfo.go:214] Couldn't parse request url.Values{"labelSelector":[]string{"name=kube-controller-manager-ip-10-0-4-229.us-west-2.compute.internal"}}: unable to parse requirement: invalid label value: "kube-controller-manager-ip-10-0-4-229.us-west-2.compute.internal": at key: "name": must be no more than 63 characters
E0925 17:57:16.220907       1 requestinfo.go:214] Couldn't parse request url.Values{"labelSelector":[]string{"name=kube-controller-manager-ip-10-0-4-229.us-west-2.compute.internal"}}: unable to parse requirement: invalid label value: "kube-controller-manager-ip-10-0-4-229.us-west-2.compute.internal": at key: "name": must be no more than 63 characters
E0925 17:57:16.222083       1 requestinfo.go:214] Couldn't parse request url.Values{"labelSelector":[]string{"name=kube-controller-manager-ip-10-0-4-229.us-west-2.compute.internal"}}: unable to parse requirement: invalid label value: "kube-controller-manager-ip-10-0-4-229.us-west-2.compute.internal": at key: "name": must be no more than 63 characters

These appear in the apiserver from time to time.

  1. Also the following logs seem to be suspicious of a problem.
E0925 20:05:55.576855       1 reflector.go:127] k8s.io/client-go/metadata/metadatainformer/informer.go:90: Failed to watch *v1.PartialObjectMetadata: failed to list *v1.PartialObjectMetadata: the server could not find the requested resource
  1. as well as
E0925 20:05:59.901695       1 route_controller.go:118] Couldn't reconcile node routes: error listing routes: unable to find route table for AWS cluster: tkg-aws-calico

which appear in the KCM

What steps did you take and what happened:

These are fresh CAPA clusters spun up using the TKG platform

What did you expect to happen:

any labels on pods would work properly with watches , and in general new clusters wouldnt have failing queries during conformance test runs

Anything else you would like to add:

I was running the K8s conformance suite via sonobuoy when seeing these. i havent yet determined wether it is the cause of these errors though or what is running these queries

Environment:

  • Cluster-api-provider-aws version: 0.5.5
  • Kubernetes version: (use kubectl version): 1.19
  • OS (e.g. from /etc/os-release):
@k8s-ci-robot k8s-ci-robot added the kind/bug Categorizes issue or PR as related to a bug. label Sep 25, 2020
@ncdc
Copy link
Contributor

ncdc commented Sep 25, 2020

Can you gist kubectl get cluster-api -A -o yaml from the management cluster?

Can you gist kubectl get pod -A -o yaml from the workload cluster?

@ncdc
Copy link
Contributor

ncdc commented Sep 25, 2020

Which log is the Failed to watch *v1.PartialObjectMetadata error from?

@jayunit100
Copy link
Contributor Author

The KCM is issuing the partial object metadata error

[kube-controller-manager-ip-10-0-0-35.us-west-2.compute.internal] E0925 21:06:14.595802       1 reflector.go:127] k8s.io/client-go/metadata/metadatainformer/informer.go:90: Failed to watch *v1.PartialObjectMetadata: failed to list *v1.PartialObjectMetadata: the server could not find the requested resource

@ncdc
Copy link
Contributor

ncdc commented Sep 25, 2020

Can you gist the full KCM log?

@jayunit100
Copy link
Contributor Author

https://gist.github.com/cd426e125a2355bcecfe9cf2f124a363 <- kubectl get pod -A

@jayunit100
Copy link
Contributor Author

jayunit100 commented Sep 25, 2020

(deleted this comment as the kcm logs were unusable, they were from a non-active kcm, will add them back when i see this again)

@ncdc
Copy link
Contributor

ncdc commented Sep 29, 2020

@jayunit100 if you can reproduce this, please let us know, and we'll see about triaging it together with a screenshare.

/priority awaiting-more-evidence
/milestone Next

@k8s-ci-robot k8s-ci-robot added the priority/awaiting-more-evidence Lowest priority. Possibly useful, but not yet enough support to actually get it done. label Sep 29, 2020
@k8s-ci-robot k8s-ci-robot added this to the Next milestone Sep 29, 2020
@nijave
Copy link

nijave commented Nov 25, 2020

Maybe 2 is related to kubernetes/kubernetes#79610 ?

@fejta-bot
Copy link

Issues go stale after 90d of inactivity.
Mark the issue as fresh with /remove-lifecycle stale.
Stale issues rot after an additional 30d of inactivity and eventually close.

If this issue is safe to close now please do so with /close.

Send feedback to sig-contributor-experience at kubernetes/community.
/lifecycle stale

@k8s-ci-robot k8s-ci-robot added the lifecycle/stale Denotes an issue or PR has remained open with no activity and has become stale. label Feb 24, 2021
@randomvariable
Copy link
Member

/close

@k8s-ci-robot
Copy link
Contributor

@randomvariable: Closing this issue.

In response to this:

/close

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
kind/bug Categorizes issue or PR as related to a bug. lifecycle/stale Denotes an issue or PR has remained open with no activity and has become stale. priority/awaiting-more-evidence Lowest priority. Possibly useful, but not yet enough support to actually get it done.
Projects
None yet
Development

No branches or pull requests

6 participants