Implement a way to time out tokens based on (in)activity by simo5 · Pull Request #17640 · openshift/origin

simo5 · 2017-12-06T19:38:57Z

When OAuthClient is configure with accessTokenTimeoutSeconds then tokens obtained with the specific client get a TimeoutsIn field that marks when the token is to be considered timed out.
The timeout is in seconds since token CreationTimestamp
As the token is used it is pushed into a bucket which is regularly flushed (for now).

This replaces #17161 which github inexplicably and unilaterally decided to close after a wrong push (can't be reopened)

simo5 · 2017-12-06T19:42:31Z

/hold
need to wait for api merge in openshift/api

enj

Here is the diffs I used:

http://pastebin.test.redhat.com/538893 (for everything but the main timeout validator file)
https://www.diffchecker.com/ln16YiA7 (for the validator file)

enj · 2017-12-06T21:59:26Z

test/integration/oauth_timeout_test.go

+			AccessTokenTimeoutSeconds: &invalid,
+			GrantMethod:               oauthapi.GrantHandlerAuto,
+		})
+		if err == nil {


Check for IsInvalid here.

enj · 2017-12-07T14:35:24Z

pkg/oauth/apis/oauth/validation/validation.go

 )

 const MinTokenLength = 32
+const MinFlushTimeout = 150


I am actually going to change flush timeout handling a little, and will put here docs on what it means

enj · 2017-12-07T14:35:45Z

pkg/oauth/apis/oauth/validation/validation.go

 	allErrs := validation.ValidateObjectMetaUpdate(&newToken.ObjectMeta, &oldToken.ObjectMeta, field.NewPath("metadata"))
 	copied := *oldToken
 	copied.ObjectMeta = newToken.ObjectMeta
+	// allow only TimeoutsIn to be changed


Most of my validation additions are missing.

Ok I think I have it now

enj · 2017-12-07T14:39:48Z

pkg/cmd/server/origin/authenticator.go

+			timeoutValidator := authnregistry.NewTimeoutValidator(accessTokenGetter, oauthClientLister, *config.OAuthConfig.TokenConfig.AccessTokenTimeoutSeconds)
+			validators = append(validators, timeoutValidator)
+			postStartHooks["openshift.io-TokenTimeoutUpdater"] = func(context genericapiserver.PostStartHookContext) error {
+				go timeoutValidator.Start(context.StopCh)


I don't really like that we have to export the type to call this, but we seem to do this in other places as well so I suppose its fine (granted controllers seem to have a Run method instead of a Start).

I think we want a defer utilruntime.HandleCrash() in the hook though.

Ok, changed Start() -> Run() and added a HandleCrash call in it

enj · 2017-12-07T14:40:22Z

pkg/auth/oauth/registry/timeoutvalidator.go

+		}
+	}
+
+	glog.Infof("Flushed %d tokens out of %d in bucket", flushedTokens, totalTokens)


enj · 2017-12-07T14:44:23Z

pkg/auth/oauth/registry/timeoutvalidator.go

+	// make sure to kill the timer when we exit
+	defer closeTimer()
+
+	updateTimerAndFlush := func() {


I think we can reset the timer to save resources and this way the timer is always stooped even when we receive from the channel (I could not tell from the docs if that was required).

resetTimerAndFlush := func() { closeTimer() nextTimer.Reset(a.flushTimeout) nextTimeout = time.Now().Add(a.flushTimeout) a.flush(nextTimeout.Add(a.safetyMargin)) }

good point, done

enj · 2017-12-07T16:12:54Z

pkg/auth/oauth/registry/timeoutvalidator.go

+	delta := a.clientTimeout(td.token.ClientName)
+	newTimeout := int32(0)
+	if delta > 0 {
+		newTimeout = int32((td.seen.Sub(td.token.CreationTimestamp.Time) + delta) / time.Second)


I had some comments explaining this math which I think are useful.

enj · 2017-12-07T16:13:30Z

pkg/auth/oauth/registry/timeoutvalidator.go

+	if oauthClient.AccessTokenTimeoutSeconds == nil {
+		return a.defaultTimeout
+	}
+	a.updateTimeouts(oauthClient)


I believe I had some extra glogs in this func and some other places in this file?

I did not import all of them as some things simply changed, any specific thing you want to generate logs out of ? You can describe the thought process about what you think should be logged too.

enj · 2017-12-07T16:17:25Z

pkg/auth/oauth/registry/timeoutvalidator.go

+		switch {
+		case err == nil:
+			flushedTokens++
+		case apierrors.IsConflict(err):


Combine the two error cases.

enj · 2017-12-07T16:17:52Z

pkg/auth/oauth/registry/timeoutvalidator.go

+			glog.V(5).Infof("Token timeout for user=%q client=%q scopes=%v was not updated: %v",
+				td.token.UserName, td.token.ClientName, td.token.Scopes, err)
+		} else {
+			flushedTokens++


Should we also count total failures?

Any token not flushed is a failure, do we need to be very explicit about it ?

simo5 · 2017-12-07T21:24:52Z

Ok I should have addressed all comments but the clock one.
I changed slightly how the defaultTimeout handling works.
Next a change to how we change the flushTimeout, current code can only make it shrink but never grow back. going to change this so we can recover after an admin fat fingered a too short interval on an oauthClient configuration

simo5 · 2017-12-08T15:16:03Z

Finally #17662 got in and I was able to properly generate the internal API changes, code has been updated

enj · 2017-12-08T20:09:31Z

pkg/auth/oauth/registry/timeoutvalidator.go

+	"github.com/openshift/origin/pkg/user/apis/user"
+)
+
+var ErrTimedout = errors.New("token timed out")


nit: I believe this can be made private.

enj · 2017-12-08T20:25:24Z

pkg/cmd/server/api/validation/oauth.go

 	}

+	if config.TokenConfig.AccessTokenTimeoutSeconds != nil {
+		if *config.TokenConfig.AccessTokenTimeoutSeconds < oauthvalidation.ReferenceTimeoutInterval {


*config.TokenConfig.AccessTokenTimeoutSeconds == 0 is valid

enj · 2017-12-08T20:33:31Z

pkg/oauth/apis/oauth/validation/validation.go

+	// to timeout earlier than they should. 0 is the exception, as this value
+	// indicates that the token does not expire, and it is an allowed new
+	// value.
+	if newToken.TimeoutsIn > 0 && newToken.TimeoutsIn < oldToken.TimeoutsIn {


I had some related validation in pkg/oauth/registry/oauthaccesstoken/strategy.go that went with this as well.

Yeah I saw that, but given we can update the field with any (valid) value, I do not see much value in adding this kind of validation just at token creation.

OK I suppose that is fine.

enj · 2017-12-11T14:48:39Z

pkg/auth/oauth/registry/timeoutvalidator.go

 }

-func (a *tokenData) timeout() time.Time {
+func (a tokenData) timeout() time.Time {


You probably want to use *tokenData to avoid copying the struct unnecessarily.

I was doing that before, but when I added RankedSet the compiler complained, changing it to not be apointer made it work.

Right because you will have to update everything to use *tokenData otherwise it will not implement the interface.

enj · 2017-12-11T14:54:04Z

pkg/cmd/server/api/validation/oauth.go

 			)))
 	}

+	if config.TokenConfig.AccessTokenTimeoutSeconds != nil {


if timeout := config.TokenConfig.AccessTokenTimeoutSeconds; timeout != nil && *timeout != 0 { is a bit easier to read.

enj · 2017-12-11T14:55:16Z

pkg/oauth/apis/oauth/validation/validation.go

+			fmt.Sprintf("cannot beless than the current value=%d", oldToken.TimeoutsIn)))
+	}
+	// negative values are not allowed either
+	if newToken.TimeoutsIn < 0 {


We want this on create as well.

enj · 2017-12-11T14:56:19Z

pkg/oauth/apis/oauth/validation/validation.go

 		allErrs = append(allErrs, ValidateScopeRestriction(restriction, field.NewPath("scopeRestrictions").Index(i))...)
 	}

+	if client.AccessTokenTimeoutSeconds != nil {


Want negative check here as well.

And same checks on update too I believe.

yeah about negative, update automatically checks for anything doen at create

enj · 2017-12-11T15:03:13Z

@simo5 please add unit tests for all the validation bits, should be easy to extend/copy existing tests.

enj

I do not think we want to log the error in these places since it is likely to leak the token value.

enj · 2017-12-11T19:30:49Z

pkg/auth/oauth/registry/timeoutvalidator.go

+		case err == nil:
+			flushedTokens++
+		case apierrors.IsConflict(err) || apierrors.IsServerTimeout(err):
+			glog.V(5).Infof("Token update deferred for token=%q, retriable error: %v",


Err actually I see you are logging the token name, do not do that xD

enj · 2017-12-11T19:30:58Z

pkg/auth/oauth/registry/timeoutvalidator.go

+				td.token.Name, err)
+			retryList = append(retryList, *td)
+		default:
+			glog.V(5).Infof("Token timeout for user=%q client=%q scopes=%v was not updated: %v",


no token name here

enj · 2017-12-11T19:31:10Z

pkg/auth/oauth/registry/timeoutvalidator.go

+	for _, td := range retryList {
+		err := a.update(td)
+		if err != nil {
+			glog.V(5).Infof("Token timeout for user=%q client=%q scopes=%v was not updated: %v",


neither here, is the err what you want me drop ? (doing that anyway)

enj

mostly nits

enj · 2017-12-11T19:36:26Z

pkg/auth/oauth/registry/timeoutvalidator.go

+
+var errTimedout = errors.New("token timed out")
+
+// Implements rankedset.Item


nit: type assertion

enj · 2017-12-11T19:37:55Z

pkg/auth/oauth/registry/timeoutvalidator.go

+		return nil
+	}
+
+	td := tokenData{


Shouldn't you just use a pointer the whole time? The channel having tokenData and the set having *tokenData is weird.

whatever :)

enj · 2017-12-11T19:41:01Z

pkg/cmd/server/api/validation/oauth.go

+		if *timeout != 0 && *timeout < oauthvalidation.ReferenceTimeoutInterval {
+			validationResults.AddErrors(field.Invalid(
+				fldPath.Child("tokenConfig", "accessTokenTimeoutSeconds"),
+				*config.TokenConfig.AccessTokenInactivityTimeoutSeconds,


nit: use *timeout on this line

enj · 2017-12-11T19:45:20Z

pkg/oauth/apiserver/auth.go


-	storage := registrystorage.New(c.ExtraOAuthConfig.OAuthAccessTokenClient, c.ExtraOAuthConfig.OAuthAuthorizeTokenClient, combinedOAuthClientGetter, registry.NewUserConversion())
+	tokentimeout := int32(0)
+	if c.ExtraOAuthConfig.Options.TokenConfig.AccessTokenInactivityTimeoutSeconds != nil {


nit: if timeout := c.ExtraOAuthConfig.Options.TokenConfig.AccessTokenInactivityTimeoutSeconds; timeout != nil would make it so you do not have to repeat that whole thing on the next line.

enj · 2017-12-11T19:58:20Z

test/integration/runner/runner_test.go


 var timeout = flag.Duration("sub.timeout", 5*time.Minute, "Specify the timeout for each sub test")
+var timeoutException = map[string]*time.Duration{
+	"TestOAuthTimeout": flag.Duration("oauth.timeout", 15*time.Minute, "Timeout for the OAuth test"),


nit: just make this a map[string]string, don't need the flag / pointer stuff.

easier this way for me

enj · 2017-12-11T19:59:38Z

test/integration/oauth_timeout_test.go

+	// Use the server and CA info
+	anonConfig := restclient.AnonymousClientConfig(clientConfig)
+
+	min := int32(150)


uh isn't this too small per validation?

it passes tests ...

hint the min timeout is reference timeout / 3 ie 100 seconds is the current absolute minimum

enj

glog comments.

enj · 2017-12-11T21:37:59Z

pkg/auth/oauth/registry/timeoutvalidator.go

+		}
+	}
+
+	glog.V(5).Infof("Successfully flushed %d tokens out of %d",


You may want a.data.Len() as well?

no, I rally only want to show what we tried to flush, and what succeeded, data.Len() is all the stuff in the queue

enj · 2017-12-11T21:42:16Z

pkg/auth/oauth/registry/timeoutvalidator.go

+		err := a.update(*td)
+		switch {
+		case err == nil:
+			flushedTokens++


A glog here may be useful.

enj · 2017-12-11T21:42:50Z

pkg/auth/oauth/registry/timeoutvalidator.go

+			glog.V(5).Infof("Token timeout for user=%q client=%q scopes=%v was not updated: %v",
+				td.token.UserName, td.token.ClientName, td.token.Scopes, err)
+		} else {
+			flushedTokens++


A glog here may be useful.

enj · 2017-12-11T21:43:56Z

pkg/auth/oauth/registry/timeoutvalidator.go

+		return a.defaultTimeout
+	}
+	if oauthClient.AccessTokenInactivityTimeoutSeconds == nil {
+		return a.defaultTimeout


A glog here may be useful.

enj · 2017-12-11T21:44:14Z

pkg/auth/oauth/registry/timeoutvalidator.go

+	if oauthClient.AccessTokenInactivityTimeoutSeconds == nil {
+		return a.defaultTimeout
+	}
+	return timeoutAsDuration(*oauthClient.AccessTokenInactivityTimeoutSeconds)


A glog here may be useful.

enj · 2017-12-12T16:58:40Z

pkg/oauth/apis/oauth/validation/validation.go


 func ValidateAccessTokenUpdate(newToken, oldToken *oauthapi.OAuthAccessToken) field.ErrorList {
 	allErrs := validation.ValidateObjectMetaUpdate(&newToken.ObjectMeta, &oldToken.ObjectMeta, field.NewPath("metadata"))
+	// since TimeoutsIn can be concurrently updated by multipe masters we do


We should error if oldToken.TimeoutsIn == 0 && newToken.TimeoutsIn != 0 to prevent a token that was never supposed to timeout from being updated to timeout. Probably needs a comment describing how this race could happen between multiple masters.

simo5 · 2018-01-03T19:11:42Z

flake: #17974

simo5 · 2018-01-03T19:13:32Z

flake: #17731

simo5 · 2018-01-03T19:14:37Z

flake: #16484

simo5 · 2018-01-03T19:17:17Z

/retest

enj · 2018-01-03T19:17:27Z

/lgtm

Manually approving the apps changes since they are generated code. David did not seem too concerned.

openshift-ci-robot · 2018-01-03T19:17:53Z

[APPROVALNOTIFIER] This PR is APPROVED

Approval requirements bypassed by manually added approval.

This pull-request has been approved by: enj, simo5

The full list of commands accepted by this bot can be found here.

Details

Needs approval from an approver in each of these OWNERS Files:

You can indicate your approval by writing /approve in a comment
You can cancel your approval by writing /approve cancel in a comment

simo5 · 2018-01-04T12:41:55Z

/retest

simo5 · 2018-01-04T13:15:17Z

/retest

simo5 · 2018-01-04T14:39:31Z

/retest

simo5 · 2018-01-04T15:06:11Z

/retest

simo5 · 2018-01-04T16:23:44Z

/retest

simo5 · 2018-01-04T16:25:47Z

flake: #17985

simo5 · 2018-01-04T21:30:49Z

/retest

simo5 · 2018-01-04T23:02:31Z

/retest

simo5 · 2018-01-05T14:57:33Z

flake: #16994

simo5 · 2018-01-05T14:57:40Z

/retest

simo5 · 2018-01-05T16:55:10Z

flake: #17697

simo5 · 2018-01-05T16:55:15Z

/retest

simo5 · 2018-01-05T20:06:53Z

/retest

openshift-bot · 2018-01-07T07:39:40Z

/retest

Please review the full test history for this PR and help us cut down flakes.

simo5 · 2018-01-07T23:27:15Z

/retest

simo5 · 2018-01-08T13:50:20Z

flake: #15630
/retest

openshift-ci-robot · 2018-01-08T16:13:09Z

@simo5: The following test failed, say /retest to rerun them all:

Test name	Commit	Details	Rerun command
ci/openshift-jenkins/extended_image_ecosystem	`0fc882a`	link	`/test extended_image_ecosystem`

Full PR test history. Your PR dashboard. Please help us cut down on flakes by linking to an open issue when you hit one in your PR.

Details

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. I understand the commands that are listed here.

simo5 · 2018-01-08T20:05:28Z

/retest

openshift-merge-robot · 2018-01-08T23:58:24Z

/test all [submit-queue is verifying that this PR is safe to merge]

openshift-merge-robot · 2018-01-09T01:24:24Z

Automatic merge from submit-queue.

openshift-ci-robot requested review from enj and juanvallejo December 6, 2017 19:39

openshift-merge-robot added needs-api-review vendor-update Touching vendor dir or related files labels Dec 6, 2017

openshift-ci-robot added the size/XL Denotes a PR that changes 500-999 lines, ignoring generated files. label Dec 6, 2017

openshift-ci-robot added the do-not-merge/hold Indicates that a PR should not merge because someone has issued a /hold command. label Dec 6, 2017

simo5 force-pushed the tokentimeout branch 3 times, most recently from 990e955 to 7026f96 Compare December 6, 2017 22:50

enj suggested changes Dec 7, 2017

View reviewed changes

simo5 force-pushed the tokentimeout branch from 7026f96 to 1799da7 Compare December 7, 2017 21:22

simo5 force-pushed the tokentimeout branch from 7a06319 to eda1084 Compare December 8, 2017 15:15

enj suggested changes Dec 8, 2017

View reviewed changes

simo5 force-pushed the tokentimeout branch from b2c879e to ffaf271 Compare December 8, 2017 22:57

openshift-ci-robot added size/XXL Denotes a PR that changes 1000+ lines, ignoring generated files. and removed size/XL Denotes a PR that changes 500-999 lines, ignoring generated files. labels Dec 8, 2017

enj reviewed Dec 11, 2017

View reviewed changes

simo5 force-pushed the tokentimeout branch from ffaf271 to 286442b Compare December 11, 2017 17:54

enj reviewed Dec 11, 2017

View reviewed changes

enj reviewed Dec 12, 2017

View reviewed changes

simo5 force-pushed the tokentimeout branch 3 times, most recently from 6cd0dc2 to c8badfe Compare December 13, 2017 19:54

openshift-ci-robot assigned enj Jan 3, 2018

openshift-ci-robot added the lgtm Indicates that a PR is ready to be merged. label Jan 3, 2018

enj added the approved Indicates a PR has been approved by an approver from all required OWNERS files. label Jan 3, 2018

openshift-merge-robot merged commit aa7dede into openshift:master Jan 9, 2018


		var errTimedout = errors.New("token timed out")

		// Implements rankedset.Item

Conversation

simo5 commented Dec 6, 2017 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

simo5 commented Dec 6, 2017

Uh oh!

enj left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

simo5 commented Dec 7, 2017

Uh oh!

simo5 commented Dec 8, 2017

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

simo5 commented Dec 6, 2017 •

edited

Loading