Skip to content
This repository has been archived by the owner on Sep 12, 2024. It is now read-only.

client: fix wrong call to google-auth-library-java #1229

Merged
merged 1 commit into from
Aug 17, 2018

Conversation

davidxia
Copy link
Contributor

@davidxia davidxia commented Aug 17, 2018

We were mistakenly calling GoogleCredentials.refreshAccessToken()
which always makes a call to retrieve a new access token regardless of expiration.
In addition, this method returns an AccessToken which we accidentally
ignored. But this method but never sets the AccessToken
for the getAccessToken() method which we subsequently called.

Instead, we should use GoogleCredentials.refreshIfExpired()
which refreshes the token if only if it's close to expiring and returns
void. Our next call to getAccessToken() will actually return the refreshed
token in this case.

See googleapis/google-auth-library-java#163

@davidxia davidxia requested review from vbhavsar and caipre August 17, 2018 18:33
@davidxia
Copy link
Contributor Author

cc @spotify/helios-team

@davidxia
Copy link
Contributor Author

before

helios -d example hosts -vv

14:24:23.979 DEBUG Utils: using HeliosClient httpTimeout=30, retryTimeout=120
14:24:24.291 DEBUG AgentProxies$DefaultAgentProxy: connected to [family=PF_UNIX path=/private/tmp/com.apple.launchd.emQ8ZoJBGr/Listeners]
14:24:24.323 DEBUG AgentOutput: Sent SSH2_AGENTC_REQUEST_IDENTITIES message to ssh-agent.
14:24:24.324 DEBUG AgentInput: Received SSH2_AGENT_IDENTITIES_ANSWER message from ssh-agent.
14:24:24.545 DEBUG AuthenticatingHttpConnector: connecting to https://1.2.3.4:443/hosts/?user=dxia
Aug 17, 2018 2:24:24 PM com.google.auth.oauth2.DefaultCredentialsProvider warnAboutProblematicCredentials
WARNING: Your application has authenticated using end user credentials from Google Cloud SDK. We recommend that most server applications use service accounts instead. If your application continues to use end user credentials from Cloud SDK, you might receive a "quota exceeded" or "API not enabled" error. For more information about service accounts, see https://cloud.google.com/docs/authentication/.
14:24:24.611 INFO  GoogleCredentialsAccessTokenSupplier: Using Google Application Default Credentials
14:24:25.083 DEBUG GoogleCredentialsAccessTokenSupplier: Exception (possibly benign) while loading Google Credentials
java.lang.NullPointerException: null
	at com.google.common.base.Preconditions.checkNotNull(Preconditions.java:770)
	at com.google.common.base.Optional.of(Optional.java:105)
	at com.spotify.helios.client.GoogleCredentialsAccessTokenSupplier.get(GoogleCredentialsAccessTokenSupplier.java:86)
	at com.spotify.helios.client.GoogleCredentialsAccessTokenSupplier.get(GoogleCredentialsAccessTokenSupplier.java:37)
	at com.spotify.helios.client.AuthenticatingHttpConnector.connect(AuthenticatingHttpConnector.java:115)
	at com.spotify.helios.client.DefaultRequestDispatcher$1.call(DefaultRequestDispatcher.java:71)
	at com.spotify.helios.client.DefaultRequestDispatcher$1.call(DefaultRequestDispatcher.java:67)
	at com.google.common.util.concurrent.TrustedListenableFutureTask$TrustedFutureInterruptibleTask.runInterruptibly(TrustedListenableFutureTask.java:111)
	at com.google.common.util.concurrent.InterruptibleTask.run(InterruptibleTask.java:58)
	at com.google.common.util.concurrent.TrustedListenableFutureTask.run(TrustedListenableFutureTask.java:75)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
14:24:25.132 DEBUG DefaultHttpConnector: req: GET https://1.2.3.4:443/hosts/?user=dxia 1 0
14:24:25.133 DEBUG HostnameVerifierProvider: configuring DefaultHostnameVerifier to expect hostname=helios-example.com
14:24:25.179 DEBUG X509CachingCertKeyCreator: using existing cert for dxia fromPaths /Users/dxia/.helios/fa733bcf.crt
14:24:25.844 DEBUG DefaultRequestDispatcher: rep: GET https://1.2.3.4:443/hosts/?user=dxia 200 2675 gzip:true
14:24:25.922 DEBUG AuthenticatingHttpConnector: connecting to https://1.2.3.4:443/hosts/statuses?user=dxia
14:24:26.047 DEBUG GoogleCredentialsAccessTokenSupplier: Exception (possibly benign) while loading Google Credentials
java.lang.NullPointerException: null
	at com.google.common.base.Preconditions.checkNotNull(Preconditions.java:770)
	at com.google.common.base.Optional.of(Optional.java:105)
	at com.spotify.helios.client.GoogleCredentialsAccessTokenSupplier.get(GoogleCredentialsAccessTokenSupplier.java:86)
	at com.spotify.helios.client.GoogleCredentialsAccessTokenSupplier.get(GoogleCredentialsAccessTokenSupplier.java:37)
	at com.spotify.helios.client.AuthenticatingHttpConnector.connect(AuthenticatingHttpConnector.java:115)
	at com.spotify.helios.client.DefaultRequestDispatcher$1.call(DefaultRequestDispatcher.java:71)
	at com.spotify.helios.client.DefaultRequestDispatcher$1.call(DefaultRequestDispatcher.java:67)
	at com.google.common.util.concurrent.TrustedListenableFutureTask$TrustedFutureInterruptibleTask.runInterruptibly(TrustedListenableFutureTask.java:111)
	at com.google.common.util.concurrent.InterruptibleTask.run(InterruptibleTask.java:58)
	at com.google.common.util.concurrent.TrustedListenableFutureTask.run(TrustedListenableFutureTask.java:75)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
14:24:26.048 DEBUG DefaultHttpConnector: req: POST https://1.2.3.4:443/hosts/statuses?user=dxia 3 2675
14:24:26.048 DEBUG HostnameVerifierProvider: configuring DefaultHostnameVerifier to expect hostname=helios-example.com
14:24:26.052 DEBUG X509CachingCertKeyCreator: using existing cert for dxia fromPaths /Users/dxia/.helios/fa733bcf.crt
14:24:26.738 DEBUG DefaultRequestDispatcher: rep: POST https://1.2.3.4:443/hosts/statuses?user=dxia 401 179 gzip:false
14:24:26.738 DEBUG HeliosClient: Server didn't return a version header!
java.lang.RuntimeException: com.spotify.helios.common.HeliosException: request failed: Response{method='POST', uri=http://helios/hosts/statuses?user=dxia, status=401, payload='Authentication required; client must provide Google access token in Authorization header.', headers={Keep-Alive=[timeout=10], Transfer-Encoding=[chunked], null=[HTTP/1.1 401 Unauthorized], Server=[nginx], Connection=[keep-alive], Date=[Fri, 17 Aug 2018 18:24:26 GMT], Content-Type=[text/plain]}}
	at com.spotify.helios.cli.command.ControlCommand.run(ControlCommand.java:135)
	at com.spotify.helios.cli.command.ControlCommand.run(ControlCommand.java:89)
	at com.spotify.helios.cli.CliMain.run(CliMain.java:74)
	at com.spotify.helios.cli.CliMain.main(CliMain.java:52)
Caused by: com.spotify.helios.common.HeliosException: request failed: Response{method='POST', uri=http://helios/hosts/statuses?user=dxia, status=401, payload='Authentication required; client must provide Google access token in Authorization header.', headers={Keep-Alive=[timeout=10], Transfer-Encoding=[chunked], null=[HTTP/1.1 401 Unauthorized], Server=[nginx], Connection=[keep-alive], Date=[Fri, 17 Aug 2018 18:24:26 GMT], Content-Type=[text/plain]}}
	at com.spotify.helios.client.HeliosClient$ConvertResponseToPojo.apply(HeliosClient.java:576)
	at com.spotify.helios.client.HeliosClient$ConvertResponseToPojo.apply(HeliosClient.java:544)
	at com.google.common.util.concurrent.AbstractTransformFuture$AsyncTransformFuture.doTransform(AbstractTransformFuture.java:211)
	at com.google.common.util.concurrent.AbstractTransformFuture$AsyncTransformFuture.doTransform(AbstractTransformFuture.java:200)
	at com.google.common.util.concurrent.AbstractTransformFuture.run(AbstractTransformFuture.java:130)
	at com.google.common.util.concurrent.MoreExecutors$DirectExecutor.execute(MoreExecutors.java:435)
	at com.google.common.util.concurrent.AbstractFuture.executeListener(AbstractFuture.java:900)
	at com.google.common.util.concurrent.AbstractFuture.complete(AbstractFuture.java:811)
	at com.google.common.util.concurrent.AbstractFuture.set(AbstractFuture.java:653)
	at com.google.common.util.concurrent.AbstractTransformFuture$TransformFuture.setResult(AbstractTransformFuture.java:245)
	at com.google.common.util.concurrent.AbstractTransformFuture.run(AbstractTransformFuture.java:177)
	at com.google.common.util.concurrent.MoreExecutors$DirectExecutor.execute(MoreExecutors.java:435)
	at com.google.common.util.concurrent.AbstractFuture.executeListener(AbstractFuture.java:900)
	at com.google.common.util.concurrent.AbstractFuture.complete(AbstractFuture.java:811)
	at com.google.common.util.concurrent.AbstractFuture.set(AbstractFuture.java:653)
	at com.google.common.util.concurrent.SettableFuture.set(SettableFuture.java:47)
	at com.spotify.helios.client.RetryingRequestDispatcher$2.onSuccess(RetryingRequestDispatcher.java:113)
	at com.spotify.helios.client.RetryingRequestDispatcher$2.onSuccess(RetryingRequestDispatcher.java:110)
	at com.google.common.util.concurrent.Futures$4.run(Futures.java:1132)
	at com.google.common.util.concurrent.MoreExecutors$DirectExecutor.execute(MoreExecutors.java:435)
	at com.google.common.util.concurrent.AbstractFuture.executeListener(AbstractFuture.java:900)
	at com.google.common.util.concurrent.AbstractFuture.complete(AbstractFuture.java:811)
	at com.google.common.util.concurrent.AbstractFuture.set(AbstractFuture.java:653)
	at com.google.common.util.concurrent.TrustedListenableFutureTask$TrustedFutureInterruptibleTask.runInterruptibly(TrustedListenableFutureTask.java:111)
	at com.google.common.util.concurrent.InterruptibleTask.run(InterruptibleTask.java:58)
	at com.google.common.util.concurrent.TrustedListenableFutureTask.run(TrustedListenableFutureTask.java:75)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

after

helios -d example hosts -vv

14:27:24.622 DEBUG AgentProxies$DefaultAgentProxy: connected to [family=PF_UNIX path=/private/tmp/com.apple.launchd.emQ8ZoJBGr/Listeners]
14:27:24.684 DEBUG AgentOutput: Sent SSH2_AGENTC_REQUEST_IDENTITIES message to ssh-agent.
14:27:24.685 DEBUG AgentInput: Received SSH2_AGENT_IDENTITIES_ANSWER message from ssh-agent.
14:27:25.052 DEBUG AuthenticatingHttpConnector: connecting to https://1.2.3.4:443/hosts/?user=dxia
Aug 17, 2018 2:27:25 PM com.google.auth.oauth2.DefaultCredentialsProvider warnAboutProblematicCredentials
WARNING: Your application has authenticated using end user credentials from Google Cloud SDK. We recommend that most server applications use service accounts instead. If your application continues to use end user credentials from Cloud SDK, you might receive a "quota exceeded" or "API not enabled" error. For more information about service accounts, see https://cloud.google.com/docs/authentication/.
14:27:25.106 INFO  GoogleCredentialsAccessTokenSupplier: Using Google Application Default Credentials
14:27:26.022 DEBUG AuthenticatingHttpConnector: Add Authorization header with bearer token
14:27:26.249 DEBUG DefaultHttpConnector: req: GET https://1.2.3.4:443/hosts/?user=dxia 2 0
14:27:26.251 DEBUG HostnameVerifierProvider: configuring DefaultHostnameVerifier to expect hostname=helios-example.com
14:27:26.328 DEBUG X509CachingCertKeyCreator: using existing cert for dxia fromPaths /Users/dxia/.helios/fa733bcf.crt
14:27:26.991 DEBUG DefaultRequestDispatcher: rep: GET https://1.2.3.4:443/hosts/?user=dxia 200 2675 gzip:true
14:27:27.050 DEBUG AuthenticatingHttpConnector: connecting to https://193.181.7.83:443/hosts/statuses?user=dxia
14:27:27.050 DEBUG AuthenticatingHttpConnector: Add Authorization header with bearer token
14:27:27.051 DEBUG DefaultHttpConnector: req: POST https://1.2.3.4:443/hosts/statuses?user=dxia 4 2675
14:27:27.052 DEBUG HostnameVerifierProvider: configuring DefaultHostnameVerifier to expect hostname=helios-example.com
14:27:27.057 DEBUG X509CachingCertKeyCreator: using existing cert for dxia fromPaths /Users/dxia/.helios/fa733bcf.crt
14:27:28.166 DEBUG DefaultRequestDispatcher: rep: POST https://1.2.3.4:443/hosts/statuses?user=dxia 200 280176 gzip:true

HOST                                        STATUS         DEPLOYED    RUNNING    CPUS    MEM      LOAD AVG    MEM USAGE    OS                         HELIOS     DOCKER           LABELS                                                                                                        

...

Copy link
Contributor

@vbhavsar vbhavsar left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM

@davidxia
Copy link
Contributor Author

davidxia commented Aug 17, 2018

This PR doesn't address the Google auth warning introduced by upgrading google-auth-library-java. This just makes the CLI actually work.

@caipre
Copy link
Contributor

caipre commented Aug 17, 2018

👍

We were mistakenly calling `GoogleCredentials.refreshAccessToken()`
which always makes a call to retrieve a new access token regardless of expiration.
In addition, this method returns an `AccessToken` which we accidentally
ignored. But this method but never sets the `AccessToken`
for the `getAccessToken()` method which we subsequently called.

Instead, we should use `GoogleCredentials.refreshIfExpired()`
which refreshes the token if only if it's close to expiring and returns
void. Our next call to `getAccessToken()` will actually return the refreshed
token in this case.

See googleapis/google-auth-library-java#163
@codecov-io
Copy link

Codecov Report

Merging #1229 into master will decrease coverage by 0.05%.
The diff coverage is 0%.

@@             Coverage Diff              @@
##             master    #1229      +/-   ##
============================================
- Coverage     52.71%   52.66%   -0.06%     
  Complexity     1623     1623              
============================================
  Files           268      268              
  Lines         13036    13036              
  Branches       1506     1506              
============================================
- Hits           6872     6865       -7     
- Misses         5644     5651       +7     
  Partials        520      520

@davidxia davidxia merged commit 0d35f4c into master Aug 17, 2018
@davidxia davidxia deleted the dxia/patch-client branch August 17, 2018 19:56
@mattnworb
Copy link
Member

was it #1227 that broke this?

@davidxia
Copy link
Contributor Author

davidxia commented Aug 21, 2018 via email

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants