Proposal on how to fix issue #692 by johanblumenberg · Pull Request #1002 · googleapis/google-auth-library-java

johanblumenberg · 2022-09-21T16:41:43Z

Questionnaire

Thank you for opening a Pull Request! Before submitting your PR, there are a few things you can do to make sure it goes smoothly:

Make sure to open an issue as a bug/issue before writing your code! That way we can discuss the change, evaluate designs, and agree on the general idea
Ensure the tests and linter pass
Code coverage does not decrease (if any source code was changed)
Appropriate docs were updated (if necessary)

Fixes #692

Problem

There is a race condition here

google-auth-library-java/oauth2_http/java/com/google/auth/oauth2/OAuth2Credentials.java

Line 252 in 429b481

final ListenableFutureTask<OAuthValue> task =

When task is completed, two things happen:

This listener executes, which sets the current value:

google-auth-library-java/oauth2_http/java/com/google/auth/oauth2/OAuth2Credentials.java

Line 261 in 429b481

task.addListener(
This code is unblocked, which signals to the caller that the refresh was completed:

google-auth-library-java/oauth2_http/java/com/google/auth/oauth2/OAuth2Credentials.java

Line 181 in 429b481

unwrapDirectFuture(refreshResult.task);

When more than one thread is involved, there is a race condition in which of these that get to execute first. Most of the time the listener executes first, and everything works. But now and then the listener is delayed, and that means that whoever is waiting for refresh() to complete will read the old token.

Logs

Adding a sleep in the listener shows that the race condition exists: https://github.com/veritru/google-auth-library-java/commit/551513b233339b952ec40366e12d448e8c7f7661

This produces the following logs:

2022-09-21 15:07:35.288 INFO --- [pool-6-thread-1] OAuth2Credentials : Starting refresh task
2022-09-21 15:07:35.289 INFO --- [pool-6-thread-2] OAuth2Credentials : refresh()
2022-09-21 15:07:35.308 INFO --- [pool-6-thread-1] OAuth2Credentials : Refresh task done
2022-09-21 15:07:35.308 INFO --- [pool-6-thread-2] OAuth2Credentials : refresh() done
2022-09-21 15:07:40.309 INFO --- [pool-6-thread-1] OAuth2Credentials : Update token info

The "refresh() done" log is the point where the caller would get and use the access token. It does not wait for the listener to actually update the current access token.

Solution Proposal

The proposed solution is to move the update of value to be done before the task is completed.

conventional-commit-lint-gcf · 2022-09-21T16:41:47Z

🤖 I detect that the PR title and the commit message differ and there's only one commit. To use the PR title for the commit history, you can use Github's automerge feature with squashing, or use automerge label. Good luck human!

-- conventional-commit-lint bot
https://conventionalcommits.org/

google-cla · 2022-09-21T16:41:47Z

Thanks for your pull request! It looks like this may be your first contribution to a Google open source project. Before we can look at your pull request, you'll need to sign a Contributor License Agreement (CLA).

View this failed invocation of the CLA check for more information.

For the most up to date status, view the checks section at the bottom of the pull request.

kurtisvg · 2022-09-22T15:34:27Z

                public OAuthValue call() throws Exception {
-                  return OAuthValue.create(refreshAccessToken(), getAdditionalHeaders());
+                  OAuthValue result = OAuthValue.create(refreshAccessToken(), getAdditionalHeaders());
+


Would it be better to move finishRefreshAsync up onto this line?

Yes, that might be better.

I don't know if there is any listener that relies on the task being completed, so I didn't want to change it.

clundin25 · 2022-09-27T22:37:26Z

LGTM, do you mind signing the CLA and updating to a conventional commit?

clundin25 · 2022-09-28T21:18:54Z

-                  return OAuthValue.create(refreshAccessToken(), getAdditionalHeaders());
+                  OAuthValue result = OAuthValue.create(refreshAccessToken(), getAdditionalHeaders());
+
+                  synchronized (lock) {


Is this lock necessary? Only one thread should be doing work on this future right?

The lock was taken in the finishRefreshAsync() method when modifying the value variable. I wasn't sure why, if it was needed to protect the value variable or something else. But you are probably right, the lock is not necessary here.

But don't take my word for it ... :)

clundin25 · 2022-09-28T21:22:53Z

There are a few test regressions introduced by this.

Hopefully @igorbernstein2 can chime in on those

clundin25 · 2022-09-29T19:46:20Z

Thanks @johanblumenberg for the fix. We are eager to get this merged so I have forked your PR here #1031 in order to resolve the test failures.

I will make sure you are credited if that is the PR that lands.

johanblumenberg · 2022-09-29T23:20:02Z

Thanks @johanblumenberg for the fix. We are eager to get this merged so I have forked your PR here #1031 in order to resolve the test failures.

@clundin25 Perfect, thanks a lot

TimurSadykov · 2022-10-18T01:34:25Z

Thanks for suggestion, closing as we are about to fix with another PR: #1031

johanblumenberg requested a review from a team September 21, 2022 16:41

product-auto-label Bot added the size: s Pull request size is small. label Sep 21, 2022

kurtisvg reviewed Sep 22, 2022

View reviewed changes

TimurSadykov requested review from TimurSadykov and igorbernstein2 September 28, 2022 10:22

fix: Proposal on how to fix issue #692

514ffe3

clundin25 reviewed Sep 28, 2022

View reviewed changes

clundin25 mentioned this pull request Sep 29, 2022

fix: Resolve race condition reported in #692 #1031

Merged

4 tasks

TimurSadykov closed this Oct 18, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Proposal on how to fix issue #692#1002

Proposal on how to fix issue #692#1002
johanblumenberg wants to merge 1 commit intogoogleapis:mainfrom
truid-app:fix-issue-692

johanblumenberg commented Sep 21, 2022

Uh oh!

conventional-commit-lint-gcf Bot commented Sep 21, 2022 •

edited

Loading

Uh oh!

google-cla Bot commented Sep 21, 2022

Uh oh!

kurtisvg Sep 22, 2022

Uh oh!

johanblumenberg Sep 23, 2022

Uh oh!

clundin25 commented Sep 27, 2022

Uh oh!

clundin25 Sep 28, 2022

Uh oh!

johanblumenberg Sep 29, 2022 •

edited

Loading

Uh oh!

clundin25 commented Sep 28, 2022 •

edited

Loading

Uh oh!

clundin25 commented Sep 29, 2022

Uh oh!

johanblumenberg commented Sep 29, 2022

Uh oh!

TimurSadykov commented Oct 18, 2022

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants

Conversation

johanblumenberg commented Sep 21, 2022

Questionnaire

Problem

Logs

Solution Proposal

Uh oh!

conventional-commit-lint-gcf Bot commented Sep 21, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

google-cla Bot commented Sep 21, 2022

Uh oh!

kurtisvg Sep 22, 2022

Choose a reason for hiding this comment

Uh oh!

johanblumenberg Sep 23, 2022

Choose a reason for hiding this comment

Uh oh!

clundin25 commented Sep 27, 2022

Uh oh!

clundin25 Sep 28, 2022

Choose a reason for hiding this comment

Uh oh!

johanblumenberg Sep 29, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

clundin25 commented Sep 28, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

clundin25 commented Sep 29, 2022

Uh oh!

johanblumenberg commented Sep 29, 2022

Uh oh!

TimurSadykov commented Oct 18, 2022

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants

conventional-commit-lint-gcf Bot commented Sep 21, 2022 •

edited

Loading

johanblumenberg Sep 29, 2022 •

edited

Loading

clundin25 commented Sep 28, 2022 •

edited

Loading