Proactively refresh access tokens before expiration #9

jwngr · 2017-04-02T23:05:25Z

Description

The SDK will now proactively refresh Google OAuth2 access tokens before they expire. In the common cases where the expiration time is greater than six minutes away, we will refresh it five minutes before it expires. In the rare cases where the expiration time is less than or equal to six minutes away, we will refresh it immediately.

One somewhat interesting result of this change is that, by introducing a setTimeout() call, the Node.js process will stay alive until the timeout either runs or the app is deleted. This broke our tests (in the sense that they hung after they reported a success) because we were not properly deleting used apps to clean up resources. It is possible this could have a similar "hanging" impact on end-users scripts if they do the same.

Code sample

N/A

cc/ @inlined - FYI.

Change-Id: Id8cc988ca5ba13a19287e203464c80171d53a64b

Change-Id: I3520e34d2d70deb9ae4dfca95239f61d9395cec4

jwngr · 2017-04-02T23:07:07Z

src/firebase-app.ts

            });
          }

+          // Establish a timeout to proactively refresh the token five minutes before it expires. In


How do you feel about the logic for when to refresh the token? We could do something more complex, but the tokens should have a high expiration time (way above five minutes) in almost all situations. The reason I chose six minutes as the cutoff point is to handle the situation where the expiration time is in five minutes and one second. I didn't want that to end up refreshing the token with only a second left, since then we would not have enough time to actually refresh the token. We could do something more complex (e.g. if expiration is less than six minutes but more than two minutes away, refresh one minute before expiration and if expiration is less than two minutes away, refresh immediately), but I don't think that really gains us anything.

I don't have a strong opinion about this. This seems fine as is.

How about not refresh at all if the expiry time is less than 6 minutes? If the backend server (erroneously) sends us tokens with a short ttl, the implemented logic will essentially force the SDK into a refresh loop.

I agree we should avoid a possible refresh loop. I do think we should handle a short expiry though since I honestly cannot say for certain when or why a short expiry would occur. I took a new approach which fixes this problem and the missing retry problem Bassam called out. Now, the SDK will attempt to refresh every minute starting at 5 minutes before expiry. So, in the standard case, we will just need one refresh at 5 minutes before expiry. In rare cases, the first refresh will fail and we will need to try a second retry at 4 minutes. In even rarer cases, we may get a short lived token (say that only last 2.5 minutes), and it will retry at 2 minutes before expiry. This should prevent endless refresh loops and add some resiliency to intermittent failures. I also added some tests for these scenarios.

Please take another look and let me know if you think this is a good compromise.

Change-Id: Idae8aaacd0b9f86980a978b8bb6a4c35695f8d6b

bojeil-google · 2017-04-03T06:42:25Z

src/firebase-app.ts

+          // instance has not already been deleted.
+          if (!this.isDeleted_) {
+            this.tokenRefreshTimeout_ = setTimeout(() => {
+              this.getToken(/* forceRefresh */ true);


While server side code is more stable than client side code, in the likelihood of getToken(true) failing for some recoverable error (retrial would fix it), the proactive token refresh would be broken here. The proactive token refresh would not restart until the developer or some service tries to get a token after expiration.

bojeil-google · 2017-04-03T06:45:35Z

src/firebase-app.ts

            });
          }

+          // Establish a timeout to proactively refresh the token five minutes before it expires. In


I don't have a strong opinion about this. This seems fine as is.

bojeil-google · 2017-04-03T06:52:30Z

src/firebase-app.ts

+          if (!this.isDeleted_) {
+            this.tokenRefreshTimeout_ = setTimeout(() => {
+              this.getToken(/* forceRefresh */ true);
+              clearTimeout(this.tokenRefreshTimeout_);


If force token refresh is called externally and it succeeds, the timeout should be cleared then, too. Otherwise you will have 2 timers running.

Great catch! I fixed this and also added a test for it.

hiranya911

Just had one minor suggestion. I'll defer to the bojeil-google for other JS-specific feedback,

hiranya911 · 2017-04-03T18:52:34Z

src/firebase-app.ts

            });
          }

+          // Establish a timeout to proactively refresh the token five minutes before it expires. In


How about not refresh at all if the expiry time is less than 6 minutes? If the backend server (erroneously) sends us tokens with a short ttl, the implemented logic will essentially force the SDK into a refresh loop.

jwngr · 2017-04-03T20:43:35Z

Thanks to you both for the reviews on this proactive refresh PR. Assigning this back to myself so I can take another crack at it. Note that I don't plan to ship this with tomorrow's 4.2.0 release. I will be aiming for the following week's release.

Change-Id: Ie8027c789138f0a9924e52056ed85042f69c9969

jwngr · 2017-04-07T22:14:43Z

test/unit/firebase-app.spec.ts

+      });
+    });
+
+    // TODO(jwenger): I simply cannot get this test to pass although it should.


I am stumped as to why this test won't pass... I assume it has something to do with mocking the timers, but the previous test works fine. I think the code is correct and it should pass.

Where does the test fail exactly?

The setTimeout() only ever fires once, even though it gets set up multiple times. So, the expect(getTokenStub.callCount).to.equal(2); check fails.

bojeil-google · 2017-04-11T00:14:39Z

test/unit/firebase-app.spec.ts

+        this.clock.tick(ONE_MINUTE_IN_MILLISECONDS);
+
+        // Ensure the token was attempted to be proactively refreshed two times.
+        expect(getTokenStub.callCount).to.equal(2);


I think it is not calling more than once for the following reason:

getToken(true) called manually and succeeds,
timeout set to 5 mins before timeout.
set clock to 5mins before expiration.
getToken(true) will be called underneath
clearTimeout(this.tokenRefreshTimeout_) will clear any pending timeout
this.cachedTokenPromise_ = Promise.resolve(this.credential_.getAccessToken()) will fail and the catch part will run
catch part will do nothing
Proactive refresh will not run again.

The thing is that I'm stubbing mockApp.INTERNAL.getToken() to always return a rejected promise. I'm not stubbing credential.getAccessToken(). So we should never get to the point where we clear the timeout since that code has been stubbed. Also, we do indeed want to clear the timeout whenever getToken() is called since we will only re-set the timeout if that fails. And the catch() on getAccessToken() re-throws the error so that should be okay.

I think it is probably better to mock the credential's getAccessToken() method instead of getToken() itself, so I'll play around a bit more with that. This is all still really puzzling though...

Ok. I suppose, we can revisit this and stub credential.getAccessToken instead. Anyway, if you tested this and it works in real life, we can proceed and revisit after. Maybe just add a note on where the test is failing and why you think this is happening for the future. Thanks.

Okay, I was able to get this to work once I moved the logic for caching getAccessToken() failures to a different spot. I think the new logic is technically more correct in the sense that it fixes the test scenario, although I don't think that is a very real-life situation. Nonetheless, it still works the same for all other situations so I think it's probably the right place for it. And now all the tests pass! Please take another look and let me know what you think.

bojeil-google · 2017-04-11T19:21:22Z

test/unit/firebase-app.spec.ts

+        this.clock.tick(ONE_MINUTE_IN_MILLISECONDS);
+
+        // Ensure the token was attempted to be proactively refreshed two times.
+        expect(getTokenStub.callCount).to.equal(2);


Ok. I suppose, we can revisit this and stub credential.getAccessToken instead. Anyway, if you tested this and it works in real life, we can proceed and revisit after. Maybe just add a note on where the test is failing and why you think this is happening for the future. Thanks.

Change-Id: I6b323d5f0574d841940f8d63bbd6cd4755fd35a9

hiranya911 · 2017-04-11T22:34:17Z

LGTM.

bojeil-google · 2017-04-11T23:13:23Z

LGTM

jwngr · 2017-04-12T04:37:41Z

Just to follow up here, I did some long running tests over the past few hours and things appear to be behaving as expected and desired! In the normal case, we refresh the token every 55 minutes. In the case of a short-lived token, we refresh at the top of the next minute. And in the case when we cannot successfully refresh the token, we retry five times before giving up. So we are good to ship this tomorrow!

bojeil-google · 2017-04-12T06:13:14Z

Cool, thanks for the update!

jwngr added 2 commits April 2, 2017 15:53

Proactively refresh access tokens before expiration

20f09fb

Change-Id: Id8cc988ca5ba13a19287e203464c80171d53a64b

Updated logic for when to refresh token

28bb48f

Change-Id: I3520e34d2d70deb9ae4dfca95239f61d9395cec4

jwngr assigned hiranya911 and bojeil-google Apr 2, 2017

jwngr requested review from bojeil-google and hiranya911 April 2, 2017 23:05

jwngr commented Apr 2, 2017

View reviewed changes

Added in missing expiresIn parameter description

af42fb1

Change-Id: Idae8aaacd0b9f86980a978b8bb6a4c35695f8d6b

bojeil-google suggested changes Apr 3, 2017

View reviewed changes

hiranya911 reviewed Apr 3, 2017

View reviewed changes

jwngr assigned jwngr and unassigned hiranya911 and bojeil-google Apr 3, 2017

Updated proactive token refresh logic

4994098

Change-Id: Ie8027c789138f0a9924e52056ed85042f69c9969

jwngr commented Apr 7, 2017

View reviewed changes

jwngr assigned hiranya911 and bojeil-google and unassigned jwngr Apr 7, 2017

bojeil-google suggested changes Apr 11, 2017

View reviewed changes

bojeil-google approved these changes Apr 11, 2017

View reviewed changes

Got all proactive token refresh tests passing

f3b06fe

Change-Id: I6b323d5f0574d841940f8d63bbd6cd4755fd35a9

jwngr assigned jwngr, hiranya911 and bojeil-google and unassigned hiranya911, bojeil-google and jwngr Apr 11, 2017

hiranya911 removed their assignment Apr 11, 2017

hiranya911 assigned jwngr Apr 11, 2017

jwngr removed their assignment Apr 11, 2017

jwngr assigned jwngr and unassigned bojeil-google Apr 11, 2017

jwngr merged commit 1467de4 into master Apr 11, 2017

jwngr deleted the jw-proactive-refresh branch April 11, 2017 23:28

jwngr removed their assignment Apr 15, 2017

Proactively refresh access tokens before expiration #9

Proactively refresh access tokens before expiration #9

Uh oh!

Conversation

jwngr commented Apr 2, 2017

Description

Code sample

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!

hiranya911 left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

jwngr commented Apr 3, 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!

hiranya911 commented Apr 11, 2017

Uh oh!

bojeil-google commented Apr 11, 2017

Uh oh!

jwngr commented Apr 12, 2017

Uh oh!

bojeil-google commented Apr 12, 2017

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants