hack/test-cmd.sh:107: executing 'oc login' fails with "error: Missing configuration"

[php-coder]

hack/test-cmd.sh has many failures, but looks like the most important is this:

github.com/openshift/origin/test/cmd/cmd-admin-namespace-setup hack/test-cmd.sh:107: executing 'oc login --server='https://172.17.0.2:28443' --certificate-authority='/tmp/openshift/init/openshift.local.config/master/ca.crt' -u test-user -p anything' expecting success 0.21s

go run hack/e2e.go -v -test --test_args='--ginkgo.focus=github\.com\/openshift\/origin\/test\/cmd\/cmd\-admin\-namespace\-setup\shack\/test\-cmd\.sh\:107\:\sexecuting\s\'oc\slogin\s\-\-server\=\'https\:\/\/172\.17\.0\.2\:28443\'\s\-\-certificate\-authority\=\'\/tmp\/openshift\/init\/openshift\.local\.config\/master\/ca\.crt\'\s\-u\stest\-user\s\-p\sanything\'\sexpecting\ssuccess$'

=== BEGIN TEST CASE ===
hack/test-cmd.sh:107: executing 'oc login --server='https://172.17.0.2:28443' --certificate-authority='/tmp/openshift/init/openshift.local.config/master/ca.crt' -u test-user -p anything' expecting success
FAILURE after 0.209s: hack/test-cmd.sh:107: executing 'oc login --server='https://172.17.0.2:28443' --certificate-authority='/tmp/openshift/init/openshift.local.config/master/ca.crt' -u test-user -p anything' expecting success: the command returned the wrong error code
There was no output from the command.
Standard error from the command:
error: Missing configuration - verify you have provided the correct host and port and that the server is currently running.
error: Missing configuration
=== END TEST CASE ===

The log is here: https://openshift-gce-devel.appspot.com/build/origin-ci-test/pr-logs/pull/17512/test_pull_request_origin_cmd/6902/

[php-coder]

This is a simple race, we need to wait unit server will be ready.

[php-coder]

It 100% reproducible on master locally (just run hack/test-cmd.sh). I also was able to fix it:

-os::cmd::expect_success "oc login --server='${KUBERNETES_MASTER}' --certificate-authority='${MASTER_CONFIG_DIR}/ca.crt' -u test-user -p anything"
+os::cmd::try_until_success "oc login --server='${KUBERNETES_MASTER}' --certificate-authority='${MASTER_CONFIG_DIR}/ca.crt' -u test-user -p anything"

The question is: would such a patch will be accepted? This race also signalizes that OpenShift server became slowly. I wasn't able to quickly identify a cause unfortunately.

CC @stevekuznetsov

[php-coder]

I submitted https://github.com/RangelReale/osincli/issues/6 to improve the error reporting here.

[php-coder]

So far I found the following:

1. the error "Missing configuration" is happening here:

   origin/vendor/github.com/RangelReale/osincli/client.go

   Lines 35 to 39 in b85f660

   	func (c *Client) initialize() error {
   	if c.config.ClientId == "" || c.config.AuthorizeUrl == "" ||
   	c.config.TokenUrl == "" || c.config.RedirectUrl == "" {
   	return errors.New("Missing configuration")
   	}

   
   I printed the values of required members and get the following output:

clientId = openshift-challenging-client, authorizeUrl = , tokenUrl = , RedirectUrl = /oauth/token/implicit

So, the caller haven't fully configured a config (authorizeUrl and tokenUrl are empty).

2. here is the caller:
   

   origin/pkg/cmd/util/tokencmd/request_token.go

   Lines 158 to 167 in b85f660

   	if o.OsinConfig == nil {
   	if err := o.SetDefaultOsinConfig(); err != nil {
   	return "", err
   	}
   	}
   	client, err := osincli.NewClient(o.OsinConfig)
   	if err != nil {
   	return "", err
   	}

   
   During debugging I found that SetDefaultOsinConfig() is being invoked. It means that this method is offender.

3. The SetDefaultOsinConfig() function:
   

   origin/pkg/cmd/util/tokencmd/request_token.go

   Lines 101 to 136 in b85f660

   	func (o *RequestTokenOptions) SetDefaultOsinConfig() error {
   	if o.OsinConfig != nil {
   	return fmt.Errorf("osin config is already set to: %#v", *o.OsinConfig)
   	}
   	// get the OAuth metadata from the server
   	rt, err := restclient.TransportFor(o.ClientConfig)
   	if err != nil {
   	return err
   	}
   	resp, err := request(rt, strings.TrimRight(o.ClientConfig.Host, "/")+oauthMetadataEndpoint, nil)
   	if err != nil {
   	return err
   	}
   	defer resp.Body.Close()
   	metadata := &util.OauthAuthorizationServerMetadata{}
   	if err := json.NewDecoder(resp.Body).Decode(metadata); err != nil {
   	return err
   	}
   	// use the metadata to build the osin config
   	config := &osincli.ClientConfig{
   	ClientId: openShiftCLIClientID,
   	AuthorizeUrl: metadata.AuthorizationEndpoint,
   	TokenUrl: metadata.TokenEndpoint,
   	RedirectUrl: util.OpenShiftOAuthTokenImplicitURL(metadata.Issuer),
   	}
   	if !o.TokenFlow && sets.NewString(metadata.CodeChallengeMethodsSupported...).Has(pkce_s256) {
   	if err := osincli.PopulatePKCE(config); err != nil {
   	return err
   	}
   	}
   	o.OsinConfig = config
   	return nil
   	}

   
   Here, we can see that authorizeUrl and tokenUrl are being filled from the response to the /.well-known/oauth-authorization-server resource.

I'm not familiar with this code, but by my opinion, in order to fix this issue, we should update SetDefaultOsinConfig() to either wait until we get non-empty data, or perhaps inspect the response body and re-try, or inspect the response code.

Also we could update a shell function that waits when server will be ready by also polling /.well-known/oauth-authorization-server endpoint (but this could hide other issues like we have)

I'm adding @enj to copy, because he added this code and probably could give an advice.

[php-coder]

or inspect the response code

Yes, there is a problem, when we invoke request() method it returns 403 error (Forbidden) because some RBAC initialization is still in progress. Later, if we invoke it again, the data will be available. We should add check for a response code here at least.

[php-coder]

request() method it returns 403 error (Forbidden) because some RBAC initialization is still in progress.

@simo5 @enj BTW do we know why initialization is slower than it was?

[simo5]

Probably because k8s RBAc forces reconciliation on each start

[enj]

@php-coder feel free to add a check to SetDefaultOsinConfig that errors out if the response code is not 200. Do not add any retry logic.

The test scripts wait for the master to report its healthy, but that does not mean the RBAC cache is ready (only that the post start hook completed).

@deads2k do we need another post start hook for such things? Or I suppose we could add further checks in hack/lib/start.sh and test/extended/alternate_launches.sh that try to guess if the RBAC bits are ready for use.

[stevekuznetsov]

We already have to wait for the kubernetes service to be running, so adding another thing to wait for is not the end of the world ... just terrible UX. Server startup is generally an edge case though that I wouldn't expect customers to hit so realistically let's just make the test scripts more robust.

[php-coder]

@enj @deads2k @simo5 When we're waiting for master, we query oc get --raw /healthz/ready. WDYT about modifying /healthz/ready so it will take into account all this RBAC reconciliation things?

[php-coder]

@php-coder feel free to add a check to SetDefaultOsinConfig that errors out if the response code is not 200.

#17606 has been submitted.

[enj]

When we're waiting for master, we query oc get --raw /healthz/ready. WDYT about modifying /healthz/ready so it will take into account all this RBAC reconciliation things?

@php-coder it already does that. But just because reconciliation finished does not mean that the RBAC shared informer cache that backs the authorizer is ready to process requests. Running a curl in a loop until it says 200 for /.well-known/oauth-authorization-server could work as a proxy (access to that URL is protected by RBAC but anymore is allowed to see it since its part of the discovery rule). oc get --raw is not a valid way to check because it will be running as part of the system:masters group and will bypass the RBAC authorizer (@deads2k #17414 probably made this start flaking by skipping the RBAC authorizer).

[stevekuznetsov]

@php-coder adding a curl for /.well-known/oauth-authorization-server would be appropriate.

[bparees]

hitting this on every run of #17314