Globus login failed with ImmatureSignatureError
Closed this issue · 10 comments
miaoneng commented
Hi Globus Team. I was trying to install globus-cli as "pip install globus-cli". I installed it in a clean virtualenv. However, when I login with globus login, it throws out ImmatureSignatureError
I tried both with and without "--no-local-server" option, and I also have personal connected endpoint software installed locally.
(.venv) jtang@DESKTOP-96VLFMB:~/globus$ globus login
You are running 'globus login', which should automatically open a browser window for you to login.
If this fails or you experience difficulty, try 'globus login --no-local-server'
---
(.venv) jtang@DESKTOP-96VLFMB:~/globus$ globus login --no-local-server
Please authenticate with Globus here:
------------------------------------
------------------------------------
Enter the resulting Authorization Code here:
ImmatureSignatureError: The token is not yet valid (iat)
Could you advise?
sirosen commented
I have two things that will help us track this down. Could you do each of the following?
- Check and confirm that your system clock is close to true time, and isn't very far back in time.
- Run this again with
--debugand share the output, i.e.globus login --no-local-server --debug
I haven't seen this particular error before, but my immediate instinct is that this is a JWT validation error due to clock drift.
Running with --debug will get us a lot more info on exactly what happened here.
I'm also going to do a little bit of research on how JWT validation behaves.
miaoneng commented
I was thinking about time at the first impression, but looks like it is not. See command log below.
(.venv) jtang@DESKTOP-96VLFMB:~/globus$ date
Wed Jul 19 12:32:01 EDT 2023
(.venv) jtang@DESKTOP-96VLFMB:~/globus$ globus login --no-local-server --debug
[DEBUG] [2023-07-19 12:32:19,966] globus_cli.parsing.commands::invoke() command invoke start
[INFO] [2023-07-19 12:32:19,991] globus_sdk.authorizers.basic::__init__() Setting up a BasicAuthorizer. It will use an auth type of Basic and cannot handle 401s.
[INFO] [2023-07-19 12:32:19,991] globus_sdk.authorizers.basic::__init__() BasicAuthorizer.username = 0181e3c0-e7f7-4db9-8cc5-397bd69f793b
[INFO] [2023-07-19 12:32:19,991] globus_sdk.client::__init__() Creating client of type <class 'globus_sdk.services.auth.client.confidential_client.ConfidentialAppAuthClient'> for service "auth"
[DEBUG] [2023-07-19 12:32:19,991] globus_sdk.config.env_vars::_load_var() on lookup, default setting: GLOBUS_SDK_ENVIRONMENT=production
[DEBUG] [2023-07-19 12:32:19,991] globus_sdk.config.env_vars::_load_var() on lookup, default setting: GLOBUS_SDK_VERIFY_SSL=True
[DEBUG] [2023-07-19 12:32:19,991] globus_sdk.config.env_vars::_load_var() on lookup, default setting: GLOBUS_SDK_HTTP_TIMEOUT=60.0
[DEBUG] [2023-07-19 12:32:19,991] globus_sdk.client::__init__() initialized transport of type <class 'globus_sdk.transport.requests.RequestsTransport'>
[DEBUG] [2023-07-19 12:32:19,991] globus_sdk.config.environments::get_service_url() Service URL Lookup for "auth" under env "production"
[DEBUG] [2023-07-19 12:32:19,991] globus_sdk.config.environments::get_service_url() Service URL Lookup Result: "auth" is at "https://auth.globus.org/"
[INFO] [2023-07-19 12:32:19,991] globus_sdk.services.auth.client.confidential_client::__init__() Finished initializing client, client_id=0181e3c0-e7f7-4db9-8cc5-397bd69f793b
[INFO] [2023-07-19 12:32:19,991] globus_sdk.services.auth.client.confidential_client::oauth2_start_flow() Starting OAuth2 Authorization Code Grant Flow
[DEBUG] [2023-07-19 12:32:19,991] globus_sdk.services.auth.flow_managers.authorization_code::__init__() Starting Authorization Code Flow with params:
[DEBUG] [2023-07-19 12:32:19,991] globus_sdk.services.auth.flow_managers.authorization_code::__init__() auth_client.client_id=0181e3c0-e7f7-4db9-8cc5-397bd69f793b
[DEBUG] [2023-07-19 12:32:19,991] globus_sdk.services.auth.flow_managers.authorization_code::__init__() redirect_uri=https://auth.globus.org/v2/web/auth-code
[DEBUG] [2023-07-19 12:32:19,991] globus_sdk.services.auth.flow_managers.authorization_code::__init__() refresh_tokens=True
[DEBUG] [2023-07-19 12:32:19,991] globus_sdk.services.auth.flow_managers.authorization_code::__init__() state=_default
[DEBUG] [2023-07-19 12:32:19,992] globus_sdk.services.auth.flow_managers.authorization_code::__init__() requested_scopes=openid profile email urn:globus:auth:scope:auth.globus.org:view_identity_set urn:globus:auth:scope:transfer.api.globus.org:all urn:globus:auth:scope:groups.api.globus.org:all urn:globus:auth:scope:search.api.globus.org:all https://auth.globus.org/scopes/524230d7-ea86-4a52-8312-86065a9e0417/timer[https://auth.globus.org/scopes/actions.globus.org/transfer/transfer[urn:globus:auth:scope:transfer.api.globus.org:all]] https://auth.globus.org/scopes/eec9b274-0c81-4334-bdc2-54e90e689b9a/manage_flows https://auth.globus.org/scopes/eec9b274-0c81-4334-bdc2-54e90e689b9a/view_flows https://auth.globus.org/scopes/eec9b274-0c81-4334-bdc2-54e90e689b9a/run https://auth.globus.org/scopes/eec9b274-0c81-4334-bdc2-54e90e689b9a/run_status https://auth.globus.org/scopes/eec9b274-0c81-4334-bdc2-54e90e689b9a/run_manage
[DEBUG] [2023-07-19 12:32:19,992] globus_sdk.services.auth.flow_managers.authorization_code::get_authorize_url() Building authorization URI. Base URL: https://auth.globus.org/v2/oauth2/authorize
[DEBUG] [2023-07-19 12:32:19,992] globus_sdk.services.auth.flow_managers.authorization_code::get_authorize_url() query_params={'prompt': 'login'}
[INFO] [2023-07-19 12:32:19,992] globus_sdk.services.auth.client.base::oauth2_get_authorize_url() Got authorization URL: https://auth.globus.org/v2/oauth2/authorize?client_id=0181e3c0-e7f7-4db9-8cc5-397bd69f793b&redirect_uri=https%3A%2F%2Fauth.globus.org%2Fv2%2Fweb%2Fauth-code&scope=openid+profile+email+urn%3Aglobus%3Aauth%3Ascope%3Aauth.globus.org%3Aview_identity_set+urn%3Aglobus%3Aauth%3Ascope%3Atransfer.api.globus.org%3Aall+urn%3Aglobus%3Aauth%3Ascope%3Agroups.api.globus.org%3Aall+urn%3Aglobus%3Aauth%3Ascope%3Asearch.api.globus.org%3Aall+https%3A%2F%2Fauth.globus.org%2Fscopes%2F524230d7-ea86-4a52-8312-86065a9e0417%2Ftimer%5Bhttps%3A%2F%2Fauth.globus.org%2Fscopes%2Factions.globus.org%2Ftransfer%2Ftransfer%5Burn%3Aglobus%3Aauth%3Ascope%3Atransfer.api.globus.org%3Aall%5D%5D+https%3A%2F%2Fauth.globus.org%2Fscopes%2Feec9b274-0c81-4334-bdc2-54e90e689b9a%2Fmanage_flows+https%3A%2F%2Fauth.globus.org%2Fscopes%2Feec9b274-0c81-4334-bdc2-54e90e689b9a%2Fview_flows+https%3A%2F%2Fauth.globus.org%2Fscopes%2Feec9b274-0c81-4334-bdc2-54e90e689b9a%2Frun+https%3A%2F%2Fauth.globus.org%2Fscopes%2Feec9b274-0c81-4334-bdc2-54e90e689b9a%2Frun_status+https%3A%2F%2Fauth.globus.org%2Fscopes%2Feec9b274-0c81-4334-bdc2-54e90e689b9a%2Frun_manage&state=_default&response_type=code&access_type=offline&prompt=login
Please authenticate with Globus here:
------------------------------------
https://auth.globus.org/v2/oauth2/authorize?client_id=0181e3c0-e7f7-4db9-8cc5-397bd69f793b&redirect_uri=https%3A%2F%2Fauth.globus.org%2Fv2%2Fweb%2Fauth-code&scope=openid+profile+email+urn%3Aglobus%3Aauth%3Ascope%3Aauth.globus.org%3Aview_identity_set+urn%3Aglobus%3Aauth%3Ascope%3Atransfer.api.globus.org%3Aall+urn%3Aglobus%3Aauth%3Ascope%3Agroups.api.globus.org%3Aall+urn%3Aglobus%3Aauth%3Ascope%3Asearch.api.globus.org%3Aall+https%3A%2F%2Fauth.globus.org%2Fscopes%2F524230d7-ea86-4a52-8312-86065a9e0417%2Ftimer%5Bhttps%3A%2F%2Fauth.globus.org%2Fscopes%2Factions.globus.org%2Ftransfer%2Ftransfer%5Burn%3Aglobus%3Aauth%3Ascope%3Atransfer.api.globus.org%3Aall%5D%5D+https%3A%2F%2Fauth.globus.org%2Fscopes%2Feec9b274-0c81-4334-bdc2-54e90e689b9a%2Fmanage_flows+https%3A%2F%2Fauth.globus.org%2Fscopes%2Feec9b274-0c81-4334-bdc2-54e90e689b9a%2Fview_flows+https%3A%2F%2Fauth.globus.org%2Fscopes%2Feec9b274-0c81-4334-bdc2-54e90e689b9a%2Frun+https%3A%2F%2Fauth.globus.org%2Fscopes%2Feec9b274-0c81-4334-bdc2-54e90e689b9a%2Frun_status+https%3A%2F%2Fauth.globus.org%2Fscopes%2Feec9b274-0c81-4334-bdc2-54e90e689b9a%2Frun_manage&state=_default&response_type=code&access_type=offline&prompt=login
------------------------------------
Enter the resulting Authorization Code here: bbRbYT0zOUTbcdPS4QveQBywS0u3eQ
[INFO] [2023-07-19 12:32:35,358] globus_sdk.services.auth.client.base::oauth2_exchange_code_for_tokens() Final Step of 3-legged OAuth2 Flows: Exchanging authorization code for token(s)
[DEBUG] [2023-07-19 12:32:35,358] globus_sdk.services.auth.flow_managers.authorization_code::exchange_code_for_tokens() Performing Authorization Code auth_code exchange. Sending client_id and client_secret
[INFO] [2023-07-19 12:32:35,358] globus_sdk.services.auth.client.base::oauth2_token() Fetching new token from Globus Auth
[DEBUG] [2023-07-19 12:32:35,358] globus_sdk.client::post() POST to /v2/oauth2/token with query_params None
[DEBUG] [2023-07-19 12:32:35,358] globus_sdk.client::request() request will hit URL: https://auth.globus.org/v2/oauth2/token
[DEBUG] [2023-07-19 12:32:35,358] globus_sdk.transport.requests::request() starting request for https://auth.globus.org/v2/oauth2/token
[DEBUG] [2023-07-19 12:32:35,358] globus_sdk.transport.requests::request() transport request state initialized
[DEBUG] [2023-07-19 12:32:35,358] globus_sdk.transport.requests::request() transport request retry cycle. attempt=0
[DEBUG] [2023-07-19 12:32:35,358] globus_sdk.transport.requests::request() request about to send
[DEBUG] [2023-07-19 12:32:35,708] globus_sdk.transport.requests::request() request success, still check should-retry
[DEBUG] [2023-07-19 12:32:35,708] globus_sdk.transport.retry::should_retry() ran retry check (default_check_expired_authorization) => RetryCheckResult.no_decision
[DEBUG] [2023-07-19 12:32:35,708] globus_sdk.transport.retry::should_retry() ran retry check (default_check_request_exception) => RetryCheckResult.no_decision
[DEBUG] [2023-07-19 12:32:35,708] globus_sdk.transport.retry::should_retry() ran retry check (default_check_retry_after_header) => RetryCheckResult.no_decision
[DEBUG] [2023-07-19 12:32:35,708] globus_sdk.transport.retry::should_retry() ran retry check (default_check_transient_error) => RetryCheckResult.no_decision
[INFO] [2023-07-19 12:32:35,708] globus_sdk.transport.requests::request() request done (success)
[DEBUG] [2023-07-19 12:32:35,709] globus_sdk.client::request() request made to URL: https://auth.globus.org/v2/oauth2/token
[DEBUG] [2023-07-19 12:32:35,709] globus_sdk.client::request() request completed with response code: 200
[INFO] [2023-07-19 12:32:35,709] globus_sdk.services.auth.response.oauth::decode_id_token() Decoding ID Token "eyJhbGciOiJSUzUxMiIsInR5cCI6IkpXVCJ9.eyJzdWIiOiJlYWUwNWY5NS1mOGY5LTQ1NTAtYTNlOC00ZmE1NzdmYmMwODUiLCJvcmdhbml6YXRpb24iOiJOL0EiLCJuYW1lIjoiTmVuZyBNaWFvIiwicHJlZmVycmVkX3VzZXJuYW1lIjoibWlhb25lbmdAZ2xvYnVzaWQub3JnIiwiaWRlbnRpdHlfcHJvdmlkZXIiOiI0MTE0Mzc0My1mM2M4LTRkNjAtYmJkYi1lZWVjYWJhODViZDkiLCJpZGVudGl0eV9wcm92aWRlcl9kaXNwbGF5X25hbWUiOiJHbG9idXMgSUQiLCJhbXIiOm51bGwsImFjciI6bnVsbCwiZW1haWwiOiJtaWFvbmVuZ0Bob3RlbC1sb2NhdGlvbi5uZXQiLCJsYXN0X2F1dGhlbnRpY2F0aW9uIjoxNjg5Nzg0MzQ5LCJpZGVudGl0eV9zZXQiOlt7InN1YiI6ImVhZTA1Zjk1LWY4ZjktNDU1MC1hM2U4LTRmYTU3N2ZiYzA4NSIsIm9yZ2FuaXphdGlvbiI6Ik4vQSIsIm5hbWUiOiJOZW5nIE1pYW8iLCJ1c2VybmFtZSI6Im1pYW9uZW5nQGdsb2J1c2lkLm9yZyIsImlkZW50aXR5X3Byb3ZpZGVyIjoiNDExNDM3NDMtZjNjOC00ZDYwLWJiZGItZWVlY2FiYTg1YmQ5IiwiaWRlbnRpdHlfcHJvdmlkZXJfZGlzcGxheV9uYW1lIjoiR2xvYnVzIElEIiwiZW1haWwiOiJtaWFvbmVuZ0Bob3RlbC1sb2NhdGlvbi5uZXQiLCJsYXN0X2F1dGhlbnRpY2F0aW9uIjoxNjg5Nzg0MzQ5fSx7InN1YiI6ImQ5ZDNjZTYxLTFjNzYtNGQ3ZS1iYzhlLWRkNTQ4Y2IyZGVhZiIsIm5hbWUiOm51bGwsInVzZXJuYW1lIjoianl0YW5nQGlkZW50aXR5LjdhNTc3Yi42ZmJkLmRhdGEuZ2xvYnVzLm9yZyIsImlkZW50aXR5X3Byb3ZpZGVyIjoiODdiZjU2NzctMGE2Ny00MmZhLWE0MDYtMmY4ODRkOGY1NzRkIiwiaWRlbnRpdHlfcHJvdmlkZXJfZGlzcGxheV9uYW1lIjoiTkNBUiBPSURDIEF1dGhlbnRpY2F0aW9uIiwiZW1haWwiOm51bGwsImxhc3RfYXV0aGVudGljYXRpb24iOjE2ODk3ODAxNzV9XSwiaXNzIjoiaHR0cHM6Ly9hdXRoLmdsb2J1cy5vcmciLCJhdWQiOiIwMTgxZTNjMC1lN2Y3LTRkYjktOGNjNS0zOTdiZDY5Zjc5M2IiLCJleHAiOjE2ODk5NTcxNTYsImlhdCI6MTY4OTc4NDM1NiwiYXRfaGFzaCI6ImhjU2hJMkhkeDIydm9ibUk2T1hUWkgza1JFbDk1QnU5VjNBb3pWVlF3VWcifQ.WrBAO9JshsaiHXwgGnaoRdcibF3t0GVCjE8vfp0HVSH4tSDWW20rEkNfQSeYvoSbddFgCHcqAroVAkfUlHNM2cO9f4dIhh0SbhjE40rtw3doE4ekilS15MCpTh0Me6CXUwi8hmUGu1baMOx3pxDA6hwckbcRAuOTNX3v0c-Z5OTeOGpxVRJ3u-38yHKmDDKHinzFrYqGXNPeIUVdWg1YWiWkJXO9Zaa3Y-__prToMbK4g1dzUIPrFETuei-l8gM2IbxVPvRjQkzt3Z7duBn8P0pY3aV9aUflF-8hRmAgiqXeqqe1k187zuqDRrOIXb7_mFlsEeKCxH9q6FT6qspQOw"
[DEBUG] [2023-07-19 12:32:35,709] globus_sdk.services.auth.response.oauth::decode_id_token() No OIDC Config provided, autofetching...
[INFO] [2023-07-19 12:32:35,709] globus_sdk.services.auth.client.base::get_openid_configuration() Fetching OIDC Config
[DEBUG] [2023-07-19 12:32:35,709] globus_sdk.client::get() GET to /.well-known/openid-configuration with query_params None
[DEBUG] [2023-07-19 12:32:35,709] globus_sdk.client::request() request will hit URL: https://auth.globus.org/.well-known/openid-configuration
[DEBUG] [2023-07-19 12:32:35,709] globus_sdk.transport.requests::request() starting request for https://auth.globus.org/.well-known/openid-configuration
[DEBUG] [2023-07-19 12:32:35,709] globus_sdk.transport.requests::request() transport request state initialized
[DEBUG] [2023-07-19 12:32:35,709] globus_sdk.transport.requests::request() transport request retry cycle. attempt=0
[DEBUG] [2023-07-19 12:32:35,709] globus_sdk.transport.requests::request() request about to send
[DEBUG] [2023-07-19 12:32:35,720] globus_sdk.transport.requests::request() request success, still check should-retry
[DEBUG] [2023-07-19 12:32:35,721] globus_sdk.transport.retry::should_retry() ran retry check (default_check_expired_authorization) => RetryCheckResult.no_decision
[DEBUG] [2023-07-19 12:32:35,721] globus_sdk.transport.retry::should_retry() ran retry check (default_check_request_exception) => RetryCheckResult.no_decision
[DEBUG] [2023-07-19 12:32:35,721] globus_sdk.transport.retry::should_retry() ran retry check (default_check_retry_after_header) => RetryCheckResult.no_decision
[DEBUG] [2023-07-19 12:32:35,721] globus_sdk.transport.retry::should_retry() ran retry check (default_check_transient_error) => RetryCheckResult.no_decision
[INFO] [2023-07-19 12:32:35,721] globus_sdk.transport.requests::request() request done (success)
[DEBUG] [2023-07-19 12:32:35,721] globus_sdk.client::request() request made to URL: https://auth.globus.org/.well-known/openid-configuration
[DEBUG] [2023-07-19 12:32:35,721] globus_sdk.client::request() request completed with response code: 200
[DEBUG] [2023-07-19 12:32:35,721] globus_sdk.services.auth.response.oauth::decode_id_token() No JWK provided, autofetching + decoding...
[INFO] [2023-07-19 12:32:35,721] globus_sdk.services.auth.client.base::get_jwk() Fetching JWK
[DEBUG] [2023-07-19 12:32:35,721] globus_sdk.services.auth.client.base::get_jwk() jwks_uri=https://auth.globus.org/jwk.json
[DEBUG] [2023-07-19 12:32:35,721] globus_sdk.client::get() GET to https://auth.globus.org/jwk.json with query_params None
[DEBUG] [2023-07-19 12:32:35,721] globus_sdk.client::request() request will hit URL: https://auth.globus.org/jwk.json
[DEBUG] [2023-07-19 12:32:35,721] globus_sdk.transport.requests::request() starting request for https://auth.globus.org/jwk.json
[DEBUG] [2023-07-19 12:32:35,721] globus_sdk.transport.requests::request() transport request state initialized
[DEBUG] [2023-07-19 12:32:35,721] globus_sdk.transport.requests::request() transport request retry cycle. attempt=0
[DEBUG] [2023-07-19 12:32:35,721] globus_sdk.transport.requests::request() request about to send
[DEBUG] [2023-07-19 12:32:35,731] globus_sdk.transport.requests::request() request success, still check should-retry
[DEBUG] [2023-07-19 12:32:35,731] globus_sdk.transport.retry::should_retry() ran retry check (default_check_expired_authorization) => RetryCheckResult.no_decision
[DEBUG] [2023-07-19 12:32:35,731] globus_sdk.transport.retry::should_retry() ran retry check (default_check_request_exception) => RetryCheckResult.no_decision
[DEBUG] [2023-07-19 12:32:35,731] globus_sdk.transport.retry::should_retry() ran retry check (default_check_retry_after_header) => RetryCheckResult.no_decision
[DEBUG] [2023-07-19 12:32:35,731] globus_sdk.transport.retry::should_retry() ran retry check (default_check_transient_error) => RetryCheckResult.no_decision
[INFO] [2023-07-19 12:32:35,732] globus_sdk.transport.requests::request() request done (success)
[DEBUG] [2023-07-19 12:32:35,732] globus_sdk.client::request() request made to URL: https://auth.globus.org/jwk.json
[DEBUG] [2023-07-19 12:32:35,732] globus_sdk.client::request() request completed with response code: 200
[DEBUG] [2023-07-19 12:32:35,732] globus_sdk.services.auth.client.base::get_jwk() JWK as_pem=True requested, decoding...
[DEBUG] [2023-07-19 12:32:35,753] globus_sdk.services.auth.client.base::get_jwk() JWK PEM decoding finished successfully
[DEBUG] [2023-07-19 12:32:35,754] globus_sdk.services.auth.response.oauth::decode_id_token() final step: decode with JWK
[DEBUG] [2023-07-19 12:32:35,756] globus_cli.parsing.commands::invoke() command invoke exit
Traceback (most recent call last):
File "/home/jtang/globus/.venv/lib/python3.10/site-packages/globus_cli/parsing/commands.py", line 220, in invoke
return super().invoke(ctx)
File "/home/jtang/globus/.venv/lib/python3.10/site-packages/globus_cli/parsing/commands.py", line 207, in invoke
return super().invoke(ctx)
File "/home/jtang/globus/.venv/lib/python3.10/site-packages/click/core.py", line 1688, in invoke
return _process_result(sub_ctx.command.invoke(sub_ctx))
File "/home/jtang/globus/.venv/lib/python3.10/site-packages/globus_cli/parsing/commands.py", line 138, in invoke
return super().invoke(ctx)
File "/home/jtang/globus/.venv/lib/python3.10/site-packages/globus_cli/parsing/commands.py", line 90, in invoke
return super().invoke(ctx)
File "/home/jtang/globus/.venv/lib/python3.10/site-packages/click/core.py", line 1434, in invoke
return ctx.invoke(self.callback, **ctx.params)
File "/home/jtang/globus/.venv/lib/python3.10/site-packages/click/core.py", line 783, in invoke
return __callback(*args, **kwargs)
File "/home/jtang/globus/.venv/lib/python3.10/site-packages/globus_cli/commands/login.py", line 132, in login_command
manager.run_login_flow(
File "/home/jtang/globus/.venv/lib/python3.10/site-packages/globus_cli/login_manager/manager.py", line 158, in run_login_flow
do_link_auth_flow(scopes, session_params=session_params)
File "/home/jtang/globus/.venv/lib/python3.10/site-packages/globus_cli/login_manager/auth_flows.py", line 54, in do_link_auth_flow
exchange_code_and_store(auth_client, auth_code)
File "/home/jtang/globus/.venv/lib/python3.10/site-packages/globus_cli/login_manager/auth_flows.py", line 119, in exchange_code_and_store
sub_new = tkn.decode_id_token()["sub"]
File "/home/jtang/globus/.venv/lib/python3.10/site-packages/globus_sdk/services/auth/response/oauth.py", line 219, in decode_id_token
decoded = jwt.decode(
File "/home/jtang/globus/.venv/lib/python3.10/site-packages/jwt/api_jwt.py", line 210, in decode
decoded = self.decode_complete(
File "/home/jtang/globus/.venv/lib/python3.10/site-packages/jwt/api_jwt.py", line 162, in decode_complete
self._validate_claims(
File "/home/jtang/globus/.venv/lib/python3.10/site-packages/jwt/api_jwt.py", line 242, in _validate_claims
self._validate_iat(payload, now, leeway)
File "/home/jtang/globus/.venv/lib/python3.10/site-packages/jwt/api_jwt.py", line 278, in _validate_iat
raise ImmatureSignatureError("The token is not yet valid (iat)")
jwt.exceptions.ImmatureSignatureError: The token is not yet valid (iat)
ImmatureSignatureError: The token is not yet valid (iat)
sirosen commented
Thanks for that detail, it confirms the suspicion that this is pyjwt-related.
Running this down, it seems that our tolerance for clock drift between the client and server is 0! (The pyjwt default.)
I find it somewhat surprising that we don't see this as a frequent issue -- but I'm talking with our team about how best to resolve.
I'm working on a fix for this issue to allow us to increase tolerance via globus-sdk, and then we will need to update globus-cli to set that tolerance value. I'll update this ticket when we have released a fix.
In terms of workarounds in the meantime, the only idea which springs to mind is to modify CLI source to add a 0.5s sleep before the token is decoded. I'd only like to get into the details of that if you need to get login working while we sort out the fix.
miaoneng commented
Thank you for looking into this. Globus CLI is not an urgent issue on my end and I can surely wait for another release for a week or so.
BTW I cloned your PR and give it a try. It looks like working.
miaoneng commented
I identified more similar error in other command usage. e.g.
globus session consent 'urn:globus:auth:scope:transfer.api.globus.org:all[*https://auth.globus.org/scopes/d33b3614-6d04-11e5-ba46-22000b92c6ec/data_access]'
You are running 'globus session consent', which should automatically open a browser window for you to authenticate with specific identities.
If this fails or you experience difficulty, try 'globus session consent --no-local-server'
---
ImmatureSignatureError: The token is not yet valid (iat)
but interestingly, this command succeeded.
sirosen commented
I forgot to circle back to this thread, but we released globus-cli v3.16.0 a few days ago and it includes an update to the globus-sdk version used which should address this issue in globus login, globus session consent, and globus session update.
Please let us know if the issue persists with the new version!
A little bit of an aside and explanation here:
iat is the token's "issued at" time, in seconds -- the time when a token was created. JWT validation is defined (at least in pyjwt, but I also think in the spec) to include checking that iat is in the past.
Assuming the clock in Globus Auth is out of sync with your local clock by a small amount (e.g. 0.1s), this will typically never be seen as an issue because the following series of events happens:
| step | time started | time finished | event |
|---|---|---|---|
| 0 | t0 | t1 | Globus Auth creates the token |
| 1 | t2 | t3 | Globus Auth sends the token to the client |
| 2 | t4 | t5 | client fetches OIDC config from Globus Auth |
| 3 | t6 | t7 | client fetches JWK from Globus Auth |
| 4 | t8 | t9 | client uses OIDC config + JWK to decode the JWT |
Step 4 is the time at which an error can occur. t0, t1, t2 are pretty nearly simultaneous, and t3 is only slightly later. But usually t8-t1 is larger than any potential clock drift.
The above debug log tells us something unusual -- step 2 and step 3 together took about 20ms. Both of those are roundtrip HTTP requests and often take on the order of 100ms each (so t7-t4 ~= 0.2s). The speed here is roughly 10x faster than what I would consider typical. The two best explanations I can come up with are a high bandwidth connection somewhere near (in terms of number of hops) Globus Auth or some kind of caching somewhere in front of Globus Auth.
We've added a default tolerance of 0.5s to the SDK. That means we can handle clock drift between a client and Auth equal to t8 - t1 + 0.5s. Those first parts are variable, but 0.5s is larger than the 0.2s we often see from t7-t4, so I would be somewhat surprised to see this issue show up again.
The error is still possible if you have a clock drifted by a larger amount, but we'll be able to adjust that tolerance in the future.
A further tangent from all of this:
The SDK supports using a cached JWK or cached OIDC config, which could pretty much eliminate the t7-t4 delay. We may see this issue crop up again if we apply that optimization, but we'd probably just increase our tolerance from 0.5s to something larger.
miaoneng commented
Reopen here.
After a brief happy week, this issue is happening again on 3.16.0 with sdk 3.25.0
globus login --debug
[DEBUG] [2023-07-31 10:40:51,252] globus_cli.parsing.commands::invoke() command invoke start
You are running 'globus login', which should automatically open a browser window for you to login.
If this fails or you experience difficulty, try 'globus login --no-local-server'
---
[INFO] [2023-07-31 10:40:51,300] globus_sdk.authorizers.basic::__init__() Setting up a BasicAuthorizer. It will use an auth type of Basic and cannot handle 401s.
[INFO] [2023-07-31 10:40:51,300] globus_sdk.authorizers.basic::__init__() BasicAuthorizer.username = 5349345f-57e8-424c-9243-a678790b7a98
[DEBUG] [2023-07-31 10:40:51,300] globus_sdk.config.env_vars::_load_var() on lookup, default setting: GLOBUS_SDK_ENVIRONMENT=production
[INFO] [2023-07-31 10:40:51,300] globus_sdk.client::__init__() Creating client of type <class 'globus_sdk.services.auth.client.confidential_client.ConfidentialAppAuthClient'> for service "auth"
[DEBUG] [2023-07-31 10:40:51,300] globus_sdk.config.environments::get_service_url() Service URL Lookup for "auth" under env "production"
[DEBUG] [2023-07-31 10:40:51,300] globus_sdk.config.environments::get_service_url() Service URL Lookup Result: "auth" is at "https://auth.globus.org/"
[DEBUG] [2023-07-31 10:40:51,301] globus_sdk.config.env_vars::_load_var() on lookup, default setting: GLOBUS_SDK_VERIFY_SSL=True
[DEBUG] [2023-07-31 10:40:51,301] globus_sdk.config.env_vars::_load_var() on lookup, default setting: GLOBUS_SDK_HTTP_TIMEOUT=60.0
[DEBUG] [2023-07-31 10:40:51,301] globus_sdk.client::__init__() initialized transport of type <class 'globus_sdk.transport.requests.RequestsTransport'>
[INFO] [2023-07-31 10:40:51,301] globus_sdk.services.auth.client.base::__init__() Finished initializing AuthClient. client_id='5349345f-57e8-424c-9243-a678790b7a98', type(authorizer)=<class 'globus_sdk.authorizers.basic.BasicAuthorizer'>
[INFO] [2023-07-31 10:40:51,301] globus_sdk.services.auth.client.confidential_client::oauth2_start_flow() Starting OAuth2 Authorization Code Grant Flow
[DEBUG] [2023-07-31 10:40:51,301] globus_sdk.services.auth.flow_managers.authorization_code::__init__() Starting Authorization Code Flow with params:
[DEBUG] [2023-07-31 10:40:51,301] globus_sdk.services.auth.flow_managers.authorization_code::__init__() auth_client.client_id=5349345f-57e8-424c-9243-a678790b7a98
[DEBUG] [2023-07-31 10:40:51,301] globus_sdk.services.auth.flow_managers.authorization_code::__init__() redirect_uri=http://localhost:53484
[DEBUG] [2023-07-31 10:40:51,301] globus_sdk.services.auth.flow_managers.authorization_code::__init__() refresh_tokens=True
[DEBUG] [2023-07-31 10:40:51,301] globus_sdk.services.auth.flow_managers.authorization_code::__init__() state=_default
[DEBUG] [2023-07-31 10:40:51,301] globus_sdk.services.auth.flow_managers.authorization_code::__init__() requested_scopes=openid profile email urn:globus:auth:scope:auth.globus.org:view_identity_set urn:globus:auth:scope:transfer.api.globus.org:all urn:globus:auth:scope:groups.api.globus.org:all urn:globus:auth:scope:search.api.globus.org:all https://auth.globus.org/scopes/524230d7-ea86-4a52-8312-86065a9e0417/timer[https://auth.globus.org/scopes/actions.globus.org/transfer/transfer[urn:globus:auth:scope:transfer.api.globus.org:all]] https://auth.globus.org/scopes/eec9b274-0c81-4334-bdc2-54e90e689b9a/manage_flows https://auth.globus.org/scopes/eec9b274-0c81-4334-bdc2-54e90e689b9a/view_flows https://auth.globus.org/scopes/eec9b274-0c81-4334-bdc2-54e90e689b9a/run https://auth.globus.org/scopes/eec9b274-0c81-4334-bdc2-54e90e689b9a/run_status https://auth.globus.org/scopes/eec9b274-0c81-4334-bdc2-54e90e689b9a/run_manage
[DEBUG] [2023-07-31 10:40:51,302] globus_sdk.services.auth.flow_managers.authorization_code::get_authorize_url() Building authorization URI. Base URL: https://auth.globus.org/v2/oauth2/authorize
[DEBUG] [2023-07-31 10:40:51,302] globus_sdk.services.auth.flow_managers.authorization_code::get_authorize_url() query_params={'prompt': 'login'}
[INFO] [2023-07-31 10:40:51,302] globus_sdk.services.auth.client.base::oauth2_get_authorize_url() Got authorization URL: https://auth.globus.org/v2/oauth2/authorize?client_id=5349345f-57e8-424c-9243-a678790b7a98&redirect_uri=http%3A%2F%2Flocalhost%3A53484&scope=openid+profile+email+urn%3Aglobus%3Aauth%3Ascope%3Aauth.globus.org%3Aview_identity_set+urn%3Aglobus%3Aauth%3Ascope%3Atransfer.api.globus.org%3Aall+urn%3Aglobus%3Aauth%3Ascope%3Agroups.api.globus.org%3Aall+urn%3Aglobus%3Aauth%3Ascope%3Asearch.api.globus.org%3Aall+https%3A%2F%2Fauth.globus.org%2Fscopes%2F524230d7-ea86-4a52-8312-86065a9e0417%2Ftimer%5Bhttps%3A%2F%2Fauth.globus.org%2Fscopes%2Factions.globus.org%2Ftransfer%2Ftransfer%5Burn%3Aglobus%3Aauth%3Ascope%3Atransfer.api.globus.org%3Aall%5D%5D+https%3A%2F%2Fauth.globus.org%2Fscopes%2Feec9b274-0c81-4334-bdc2-54e90e689b9a%2Fmanage_flows+https%3A%2F%2Fauth.globus.org%2Fscopes%2Feec9b274-0c81-4334-bdc2-54e90e689b9a%2Fview_flows+https%3A%2F%2Fauth.globus.org%2Fscopes%2Feec9b274-0c81-4334-bdc2-54e90e689b9a%2Frun+https%3A%2F%2Fauth.globus.org%2Fscopes%2Feec9b274-0c81-4334-bdc2-54e90e689b9a%2Frun_status+https%3A%2F%2Fauth.globus.org%2Fscopes%2Feec9b274-0c81-4334-bdc2-54e90e689b9a%2Frun_manage&state=_default&response_type=code&access_type=offline&prompt=login
[INFO] [2023-07-31 10:40:59,410] globus_sdk.services.auth.client.base::oauth2_exchange_code_for_tokens() Final Step of 3-legged OAuth2 Flows: Exchanging authorization code for token(s)
[DEBUG] [2023-07-31 10:40:59,410] globus_sdk.services.auth.flow_managers.authorization_code::exchange_code_for_tokens() Performing Authorization Code auth_code exchange. Sending client_id and client_secret
[INFO] [2023-07-31 10:40:59,411] globus_sdk.services.auth.client.base::oauth2_token() Fetching new token from Globus Auth
[DEBUG] [2023-07-31 10:40:59,411] globus_sdk.client::post() POST to /v2/oauth2/token with query_params None
[DEBUG] [2023-07-31 10:40:59,411] globus_sdk.client::request() request will hit URL: https://auth.globus.org/v2/oauth2/token
[DEBUG] [2023-07-31 10:40:59,411] globus_sdk.transport.requests::request() starting request for https://auth.globus.org/v2/oauth2/token
[DEBUG] [2023-07-31 10:40:59,411] globus_sdk.transport.requests::request() transport request state initialized
[DEBUG] [2023-07-31 10:40:59,411] globus_sdk.transport.requests::request() transport request retry cycle. attempt=0
[DEBUG] [2023-07-31 10:40:59,411] globus_sdk.transport.requests::request() request about to send
[DEBUG] [2023-07-31 10:40:59,719] globus_sdk.transport.requests::request() request success, still check should-retry
[DEBUG] [2023-07-31 10:40:59,720] globus_sdk.transport.retry::should_retry() ran retry check (default_check_expired_authorization) => RetryCheckResult.no_decision
[DEBUG] [2023-07-31 10:40:59,720] globus_sdk.transport.retry::should_retry() ran retry check (default_check_request_exception) => RetryCheckResult.no_decision
[DEBUG] [2023-07-31 10:40:59,720] globus_sdk.transport.retry::should_retry() ran retry check (default_check_retry_after_header) => RetryCheckResult.no_decision
[DEBUG] [2023-07-31 10:40:59,721] globus_sdk.transport.retry::should_retry() ran retry check (default_check_transient_error) => RetryCheckResult.no_decision
[INFO] [2023-07-31 10:40:59,721] globus_sdk.transport.requests::request() request done (success)
[DEBUG] [2023-07-31 10:40:59,721] globus_sdk.client::request() request made to URL: https://auth.globus.org/v2/oauth2/token
[DEBUG] [2023-07-31 10:40:59,721] globus_sdk.client::request() request completed with response code: 200
[INFO] [2023-07-31 10:40:59,721] globus_sdk.services.auth.response.oauth::decode_id_token() Decoding ID Token "eyJhbGciOiJSUzUxMiIsInR5cCI6IkpXVCJ9.eyJzdWIiOiJlYWUwNWY5NS1mOGY5LTQ1NTAtYTNlOC00ZmE1NzdmYmMwODUiLCJvcmdhbml6YXRpb24iOiJOL0EiLCJuYW1lIjoiTmVuZyBNaWFvIiwicHJlZmVycmVkX3VzZXJuYW1lIjoibWlhb25lbmdAZ2xvYnVzaWQub3JnIiwiaWRlbnRpdHlfcHJvdmlkZXIiOiI0MTE0Mzc0My1mM2M4LTRkNjAtYmJkYi1lZWVjYWJhODViZDkiLCJpZGVudGl0eV9wcm92aWRlcl9kaXNwbGF5X25hbWUiOiJHbG9idXMgSUQiLCJhbXIiOm51bGwsImFjciI6bnVsbCwiZW1haWwiOiJtaWFvbmVuZ0Bob3RlbC1sb2NhdGlvbi5uZXQiLCJsYXN0X2F1dGhlbnRpY2F0aW9uIjoxNjkwODE0NDYwLCJpZGVudGl0eV9zZXQiOlt7InN1YiI6ImVhZTA1Zjk1LWY4ZjktNDU1MC1hM2U4LTRmYTU3N2ZiYzA4NSIsIm9yZ2FuaXphdGlvbiI6Ik4vQSIsIm5hbWUiOiJOZW5nIE1pYW8iLCJ1c2VybmFtZSI6Im1pYW9uZW5nQGdsb2J1c2lkLm9yZyIsImlkZW50aXR5X3Byb3ZpZGVyIjoiNDExNDM3NDMtZjNjOC00ZDYwLWJiZGItZWVlY2FiYTg1YmQ5IiwiaWRlbnRpdHlfcHJvdmlkZXJfZGlzcGxheV9uYW1lIjoiR2xvYnVzIElEIiwiZW1haWwiOiJtaWFvbmVuZ0Bob3RlbC1sb2NhdGlvbi5uZXQiLCJsYXN0X2F1dGhlbnRpY2F0aW9uIjoxNjkwODE0NDYwfSx7InN1YiI6ImQ5ZDNjZTYxLTFjNzYtNGQ3ZS1iYzhlLWRkNTQ4Y2IyZGVhZiIsIm5hbWUiOm51bGwsInVzZXJuYW1lIjoianl0YW5nQGlkZW50aXR5LjdhNTc3Yi42ZmJkLmRhdGEuZ2xvYnVzLm9yZyIsImlkZW50aXR5X3Byb3ZpZGVyIjoiODdiZjU2NzctMGE2Ny00MmZhLWE0MDYtMmY4ODRkOGY1NzRkIiwiaWRlbnRpdHlfcHJvdmlkZXJfZGlzcGxheV9uYW1lIjoiTkNBUiBPSURDIEF1dGhlbnRpY2F0aW9uIiwiZW1haWwiOm51bGwsImxhc3RfYXV0aGVudGljYXRpb24iOjE2OTA0Mjg5OTZ9XSwiaXNzIjoiaHR0cHM6Ly9hdXRoLmdsb2J1cy5vcmciLCJhdWQiOiI1MzQ5MzQ1Zi01N2U4LTQyNGMtOTI0My1hNjc4NzkwYjdhOTgiLCJleHAiOjE2OTA5ODcyNjIsImlhdCI6MTY5MDgxNDQ2MiwiYXRfaGFzaCI6ImJZaDBYMEdGVDlpMldnU01lVWZrLTdmVVRFMTdkcDRXakxhR3l6ZUxNR2cifQ.WNcNN0U1iGPEkqcCUk1h1YoxG3NdPZd92f2sEnrHcpv0k9ffQErd8you9PO0NnM-ZRxWRTdkh4rewHxN_cKdpf1uTixCQ2IhK2RXKyxsqH9s-HSSOjaCHWh_pOCwfLSiElzEZiPjnu66ZUyw8YOs2v07AR1PJVzl9oPhK9ZBewzWhXbaMF3BlZmTAsa-V1t-NjEXvQ6wkM7pKW-thZfMrro6s5OVj7YJPqVKbQuhascvWEdlAz5jW-Mf49sCnbNLepWbHB9lfLpUFqrt56AC-5I_RXgwgI_Vs9NfwQ6TASKiEQR-SDxKL76MGi7C8t0j4TsigM5gA6GFbF2NsuV6gA"
[DEBUG] [2023-07-31 10:40:59,722] globus_sdk.services.auth.response.oauth::decode_id_token() No OIDC Config provided, autofetching...
[INFO] [2023-07-31 10:40:59,722] globus_sdk.services.auth.client.base::get_openid_configuration() Fetching OIDC Config
[DEBUG] [2023-07-31 10:40:59,722] globus_sdk.client::get() GET to /.well-known/openid-configuration with query_params None
[DEBUG] [2023-07-31 10:40:59,722] globus_sdk.client::request() request will hit URL: https://auth.globus.org/.well-known/openid-configuration
[DEBUG] [2023-07-31 10:40:59,723] globus_sdk.transport.requests::request() starting request for https://auth.globus.org/.well-known/openid-configuration
[DEBUG] [2023-07-31 10:40:59,723] globus_sdk.transport.requests::request() transport request state initialized
[DEBUG] [2023-07-31 10:40:59,723] globus_sdk.transport.requests::request() transport request retry cycle. attempt=0
[DEBUG] [2023-07-31 10:40:59,723] globus_sdk.transport.requests::request() request about to send
[DEBUG] [2023-07-31 10:40:59,735] globus_sdk.transport.requests::request() request success, still check should-retry
[DEBUG] [2023-07-31 10:40:59,735] globus_sdk.transport.retry::should_retry() ran retry check (default_check_expired_authorization) => RetryCheckResult.no_decision
[DEBUG] [2023-07-31 10:40:59,735] globus_sdk.transport.retry::should_retry() ran retry check (default_check_request_exception) => RetryCheckResult.no_decision
[DEBUG] [2023-07-31 10:40:59,735] globus_sdk.transport.retry::should_retry() ran retry check (default_check_retry_after_header) => RetryCheckResult.no_decision
[DEBUG] [2023-07-31 10:40:59,735] globus_sdk.transport.retry::should_retry() ran retry check (default_check_transient_error) => RetryCheckResult.no_decision
[INFO] [2023-07-31 10:40:59,736] globus_sdk.transport.requests::request() request done (success)
[DEBUG] [2023-07-31 10:40:59,736] globus_sdk.client::request() request made to URL: https://auth.globus.org/.well-known/openid-configuration
[DEBUG] [2023-07-31 10:40:59,736] globus_sdk.client::request() request completed with response code: 200
[DEBUG] [2023-07-31 10:40:59,736] globus_sdk.services.auth.response.oauth::decode_id_token() No JWK provided, autofetching + decoding...
[INFO] [2023-07-31 10:40:59,736] globus_sdk.services.auth.client.base::get_jwk() Fetching JWK
[DEBUG] [2023-07-31 10:40:59,737] globus_sdk.services.auth.client.base::get_jwk() jwks_uri=https://auth.globus.org/jwk.json
[DEBUG] [2023-07-31 10:40:59,737] globus_sdk.client::get() GET to https://auth.globus.org/jwk.json with query_params None
[DEBUG] [2023-07-31 10:40:59,737] globus_sdk.client::request() request will hit URL: https://auth.globus.org/jwk.json
[DEBUG] [2023-07-31 10:40:59,737] globus_sdk.transport.requests::request() starting request for https://auth.globus.org/jwk.json
[DEBUG] [2023-07-31 10:40:59,737] globus_sdk.transport.requests::request() transport request state initialized
[DEBUG] [2023-07-31 10:40:59,737] globus_sdk.transport.requests::request() transport request retry cycle. attempt=0
[DEBUG] [2023-07-31 10:40:59,737] globus_sdk.transport.requests::request() request about to send
[DEBUG] [2023-07-31 10:40:59,748] globus_sdk.transport.requests::request() request success, still check should-retry
[DEBUG] [2023-07-31 10:40:59,748] globus_sdk.transport.retry::should_retry() ran retry check (default_check_expired_authorization) => RetryCheckResult.no_decision
[DEBUG] [2023-07-31 10:40:59,748] globus_sdk.transport.retry::should_retry() ran retry check (default_check_request_exception) => RetryCheckResult.no_decision
[DEBUG] [2023-07-31 10:40:59,749] globus_sdk.transport.retry::should_retry() ran retry check (default_check_retry_after_header) => RetryCheckResult.no_decision
[DEBUG] [2023-07-31 10:40:59,749] globus_sdk.transport.retry::should_retry() ran retry check (default_check_transient_error) => RetryCheckResult.no_decision
[INFO] [2023-07-31 10:40:59,749] globus_sdk.transport.requests::request() request done (success)
[DEBUG] [2023-07-31 10:40:59,749] globus_sdk.client::request() request made to URL: https://auth.globus.org/jwk.json
[DEBUG] [2023-07-31 10:40:59,749] globus_sdk.client::request() request completed with response code: 200
[DEBUG] [2023-07-31 10:40:59,749] globus_sdk.services.auth.client.base::get_jwk() JWK as_pem=True requested, decoding...
[DEBUG] [2023-07-31 10:40:59,767] globus_sdk.services.auth.client.base::get_jwk() JWK PEM decoding finished successfully
[DEBUG] [2023-07-31 10:40:59,767] globus_sdk.services.auth.response.oauth::decode_id_token() final step: decode with JWK
[DEBUG] [2023-07-31 10:40:59,768] globus_cli.parsing.commands::invoke() command invoke exit
Traceback (most recent call last):
File "C:\Project\GlobusCLI\.venv\Lib\site-packages\globus_cli\parsing\commands.py", line 220, in invoke
return super().invoke(ctx)
^^^^^^^^^^^^^^^^^^^
File "C:\Project\GlobusCLI\.venv\Lib\site-packages\globus_cli\parsing\commands.py", line 207, in invoke
return super().invoke(ctx)
^^^^^^^^^^^^^^^^^^^
File "C:\Project\GlobusCLI\.venv\Lib\site-packages\click\core.py", line 1688, in invoke
return _process_result(sub_ctx.command.invoke(sub_ctx))
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "C:\Project\GlobusCLI\.venv\Lib\site-packages\globus_cli\parsing\commands.py", line 138, in invoke
return super().invoke(ctx)
^^^^^^^^^^^^^^^^^^^
File "C:\Project\GlobusCLI\.venv\Lib\site-packages\globus_cli\parsing\commands.py", line 90, in invoke
return super().invoke(ctx)
^^^^^^^^^^^^^^^^^^^
File "C:\Project\GlobusCLI\.venv\Lib\site-packages\click\core.py", line 1434, in invoke
return ctx.invoke(self.callback, **ctx.params)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "C:\Project\GlobusCLI\.venv\Lib\site-packages\click\core.py", line 783, in invoke
return __callback(*args, **kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "C:\Project\GlobusCLI\.venv\Lib\site-packages\globus_cli\commands\login.py", line 132, in login_command
manager.run_login_flow(
File "C:\Project\GlobusCLI\.venv\Lib\site-packages\globus_cli\login_manager\manager.py", line 163, in run_login_flow
do_local_server_auth_flow(scopes, session_params=session_params)
File "C:\Project\GlobusCLI\.venv\Lib\site-packages\globus_cli\login_manager\auth_flows.py", line 104, in do_local_server_auth_flow
exchange_code_and_store(auth_client, auth_code)
File "C:\Project\GlobusCLI\.venv\Lib\site-packages\globus_cli\login_manager\auth_flows.py", line 119, in exchange_code_and_store
sub_new = tkn.decode_id_token()["sub"]
^^^^^^^^^^^^^^^^^^^^^
File "C:\Project\GlobusCLI\.venv\Lib\site-packages\globus_sdk\services\auth\response\oauth.py", line 226, in decode_id_token
decoded = jwt.decode(
^^^^^^^^^^^
File "C:\Project\GlobusCLI\.venv\Lib\site-packages\jwt\api_jwt.py", line 210, in decode
decoded = self.decode_complete(
^^^^^^^^^^^^^^^^^^^^^
File "C:\Project\GlobusCLI\.venv\Lib\site-packages\jwt\api_jwt.py", line 162, in decode_complete
self._validate_claims(
File "C:\Project\GlobusCLI\.venv\Lib\site-packages\jwt\api_jwt.py", line 242, in _validate_claims
self._validate_iat(payload, now, leeway)
File "C:\Project\GlobusCLI\.venv\Lib\site-packages\jwt\api_jwt.py", line 278, in _validate_iat
raise ImmatureSignatureError("The token is not yet valid (iat)")
jwt.exceptions.ImmatureSignatureError: The token is not yet valid (iat)
ImmatureSignatureError: The token is not yet valid (iat)
miaoneng commented
Ok, some quick updates, I re-sync my time with NTP, looks like my machine is 2.x seconds behind NTP clock. but I honestly feel the tolerance should be somehow tuned.
sirosen commented
Hi there! We've been discussing your case within our team a little to try to decide on a reasonable value to crank this up to.
Our previous fix made the tolerance being tunable, so now it's really just a matter of picking and setting a value, and then releasing that fix.
We've done a little bit of research and we're tending towards a 64s interval, which matches some prior art and is in the category of "big enough for days without a clock sync on modern hardware, but small enough that we're not discarding the validation entirely".
I'll drop another update here when we do a release.
sirosen commented
There was a long delay before we were able to release this fix -- an unfortunate side-effect of our team trying to balance a number of concerns within the CLI codebase.
However, we finally have a release out as of today with a more lenient leeway for JWT validation.
Please let me know if you continue to see issues, but everything should work for you on the latest version!