Kubectl: Too large oidc token, over nginx proxy returns useless error message

[Thoro]

What happened:
I am using dex with oidc auth in kubectl to access my kubernetes cluster via an nginx proxy (logging of requests etc). At some point I added more groups to my user, which affected the token, which is now 4930 bytes large. Due to nginx default settings of http2_max_field_size with the value of 4k, nginx was SILENTLY (only info+ mode showed a message) dropping the connection, and kubectl reported the following errors:

on mac osx (1.18.8):

"Error from server (InternalError): an error on the server ("") has prevented the request from succeeding" 

on linux (1.16.1):

"Unable to connect to the server: http2 : server sent GOAWAY and closed the connection; LastStreamID=1, ErrCode=ENHANCE_YOUR_CALM, debug=""'

The problem is that contacting kube-apiserver directly does work fine.

What you expected to happen:
Some kind of warning, or a hint that something might be too big.

How to reproduce it (as minimally and precisely as possible):
Setup default nginx with simple proxing to kube-apiserver, use oidc authentication, and get a token that is > 4096 (4k) bytes

Anything else we need to know?:
It's clear to me that this issue stems from nginx, but maybe it's sensible thing to warn a user in case this happens?

Environment:

• Kubernetes client and server versions (use kubectl version): see above
• Cloud provider or hardware configuration: baremetal
• OS (e.g: cat /etc/os-release): CentOS 7

[k8s-ci-robot]

@Thoro: This issue is currently awaiting triage.

SIG CLI takes a lead on issue triage for this repo, but any Kubernetes member can accept issues by applying the triage/accepted label.

The triage/accepted label can be added by org members by writing /triage accepted in a comment.

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.

[eddiezane]

@Thoro can you please provide the full -v 9 verbose log output with this on the latest version of kubectl (1.20).

/triage needs-information

[Thoro]

@eddiezane Pretty hard, would have to break my whole cluster authentication.

The basic issue is not a bug in kubectl, it's that nginx drops the connection, but based on the Go error message it's very hard to figure out why it's happening.

Edit: Actually, I can just break the auth token fully and then it will also do that ... will provide logs in a few min

[Thoro]

kubectl version
Client Version: version.Info{Major:"1", Minor:"20", GitVersion:"v1.20.0", GitCommit:"af46c47ce925f4c4ad5cc8d1fca46c7b77d13b38", GitTreeState:"clean", BuildDate:"2020-12-08T17:59:43Z", GoVersion:"go1.15.5", Compiler:"gc", Platform:"darwin/amd64"}
Error from server (InternalError): an error on the server ("") has prevented the request from succeeding

kubectl version -v 9
I1209 18:53:32.660257   31612 loader.go:379] Config loaded from file:  /Users/thomas/.kube/config
I1209 18:53:32.662436   31612 round_trippers.go:425] curl -k -v -XGET  -H "Accept: application/json, */*" -H "User-Agent: kubectl/v1.20.0 (darwin/amd64) kubernetes/af46c47" 'https://kubernetes/version?timeout=32s'
I1209 18:53:32.864874   31612 round_trippers.go:445] GET https://kubernetes/version?timeout=32s  in 202 milliseconds
I1209 18:53:32.864905   31612 round_trippers.go:451] Response Headers:
I1209 18:53:32.865625   31612 request.go:943] Got a Retry-After 1s response for attempt 1 to https://kubernetes/version?timeout=32s
I1209 18:53:33.869744   31612 round_trippers.go:425] curl -k -v -XGET  -H "Accept: application/json, */*" -H "User-Agent: kubectl/v1.20.0 (darwin/amd64) kubernetes/af46c47" 'https://kubernetes/version?timeout=32s'
I1209 18:53:33.944431   31612 round_trippers.go:445] GET https://kubernetes/version?timeout=32s  in 74 milliseconds
I1209 18:53:33.944455   31612 round_trippers.go:451] Response Headers:
I1209 18:53:33.944514   31612 request.go:943] Got a Retry-After 1s response for attempt 2 to https://kubernetes/version?timeout=32s
I1209 18:53:34.947268   31612 round_trippers.go:425] curl -k -v -XGET  -H "Accept: application/json, */*" -H "User-Agent: kubectl/v1.20.0 (darwin/amd64) kubernetes/af46c47" 'https://kubernetes/version?timeout=32s'
I1209 18:53:35.030514   31612 round_trippers.go:445] GET https://kubernetes/version?timeout=32s  in 83 milliseconds
I1209 18:53:35.030544   31612 round_trippers.go:451] Response Headers:
I1209 18:53:35.030583   31612 request.go:943] Got a Retry-After 1s response for attempt 3 to https://kubernetes/version?timeout=32s
I1209 18:53:36.030879   31612 round_trippers.go:425] curl -k -v -XGET  -H "Accept: application/json, */*" -H "User-Agent: kubectl/v1.20.0 (darwin/amd64) kubernetes/af46c47" 'https://kubernetes/version?timeout=32s'
I1209 18:53:36.099557   31612 round_trippers.go:445] GET https://kubernetes/version?timeout=32s  in 68 milliseconds
I1209 18:53:36.099582   31612 round_trippers.go:451] Response Headers:
Client Version: version.Info{Major:"1", Minor:"20", GitVersion:"v1.20.0", GitCommit:"af46c47ce925f4c4ad5cc8d1fca46c7b77d13b38", GitTreeState:"clean", BuildDate:"2020-12-08T17:59:43Z", GoVersion:"go1.15.5", Compiler:"gc", Platform:"darwin/amd64"}
I1209 18:53:36.099724   31612 helpers.go:234] Connection error: Get https://kubernetes/version?timeout=32s: write tcp 10.8.100.3:54807->10.21.240.40:443: write: broken pipe
F1209 18:53:36.099771   31612 helpers.go:115] Unable to connect to the server: write tcp 10.8.100.3:54807->10.21.240.40:443: write: broken pipe
goroutine 1 [running]:
k8s.io/kubernetes/vendor/k8s.io/klog/v2.stacks(0xc00012a001, 0xc00007a000, 0x90, 0x213)
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/k8s.io/klog/v2/klog.go:1026 +0xb9
k8s.io/kubernetes/vendor/k8s.io/klog/v2.(*loggingT).output(0x366fd80, 0xc000000003, 0x0, 0x0, 0xc000172070, 0x34507db, 0xa, 0x73, 0x100e000)
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/k8s.io/klog/v2/klog.go:975 +0x19b
k8s.io/kubernetes/vendor/k8s.io/klog/v2.(*loggingT).printDepth(0x366fd80, 0xc000000003, 0x0, 0x0, 0x0, 0x0, 0x2, 0xc000436970, 0x1, 0x1)
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/k8s.io/klog/v2/klog.go:732 +0x16f
k8s.io/kubernetes/vendor/k8s.io/klog/v2.FatalDepth(...)
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/k8s.io/klog/v2/klog.go:1488
k8s.io/kubernetes/vendor/k8s.io/kubectl/pkg/cmd/util.fatal(0xc00018f730, 0x61, 0x1)
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/k8s.io/kubectl/pkg/cmd/util/helpers.go:93 +0x26e
k8s.io/kubernetes/vendor/k8s.io/kubectl/pkg/cmd/util.checkErr(0x28ed520, 0xc0000b5200, 0x27b5fe8)
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/k8s.io/kubectl/pkg/cmd/util/helpers.go:188 +0x945
k8s.io/kubernetes/vendor/k8s.io/kubectl/pkg/cmd/util.CheckErr(...)
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/k8s.io/kubectl/pkg/cmd/util/helpers.go:115
k8s.io/kubernetes/vendor/k8s.io/kubectl/pkg/cmd/version.NewCmdVersion.func1(0xc000a50dc0, 0xc000333720, 0x0, 0x2)
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/k8s.io/kubectl/pkg/cmd/version/version.go:79 +0x117
k8s.io/kubernetes/vendor/github.com/spf13/cobra.(*Command).execute(0xc000a50dc0, 0xc000333700, 0x2, 0x2, 0xc000a50dc0, 0xc000333700)
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/github.com/spf13/cobra/command.go:854 +0x2c2
k8s.io/kubernetes/vendor/github.com/spf13/cobra.(*Command).ExecuteC(0xc00003cb00, 0xc00012c120, 0xc000130040, 0x4)
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/github.com/spf13/cobra/command.go:958 +0x375
k8s.io/kubernetes/vendor/github.com/spf13/cobra.(*Command).Execute(...)
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/github.com/spf13/cobra/command.go:895
main.main()
    _output/dockerized/go/src/k8s.io/kubernetes/cmd/kubectl/kubectl.go:49 +0x21d

goroutine 18 [chan receive]:
k8s.io/kubernetes/vendor/k8s.io/klog/v2.(*loggingT).flushDaemon(0x366fd80)
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/k8s.io/klog/v2/klog.go:1169 +0x8b
created by k8s.io/kubernetes/vendor/k8s.io/klog/v2.init.0
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/k8s.io/klog/v2/klog.go:417 +0xdf

goroutine 6 [select]:
k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.BackoffUntil(0x27b5f08, 0x28ebcc0, 0xc00071a030, 0x1, 0xc000108b40)
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:167 +0x149
k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.JitterUntil(0x27b5f08, 0x12a05f200, 0x0, 0x1, 0xc000108b40)
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:133 +0x98
k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait.Until(0x27b5f08, 0x12a05f200, 0xc000108b40)
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:90 +0x4d
created by k8s.io/kubernetes/vendor/k8s.io/kubectl/pkg/util/logs.InitLogs
    /workspace/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/vendor/k8s.io/kubectl/pkg/util/logs/logs.go:51 +0x96

[eddiezane]

Thanks for the output.

The error you were getting from 1.16 seems much more actionable.

cc @soltysh

[fejta-bot]

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

[fejta-bot]

Stale issues rot after 30d of inactivity.
Mark the issue as fresh with /remove-lifecycle rotten.
Rotten issues close after an additional 30d of inactivity.

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

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

[fejta-bot]

Rotten issues close after 30d of inactivity.
Reopen the issue with /reopen.
Mark the issue as fresh with /remove-lifecycle rotten.

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

[k8s-ci-robot]

@fejta-bot: Closing this issue.

In response to this:

Rotten issues close after 30d of inactivity.
Reopen the issue with /reopen.
Mark the issue as fresh with /remove-lifecycle rotten.

Send feedback to sig-contributor-experience at kubernetes/community.
/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.