Token expires after 1 hour

[deathtenk]

Hello, first of all thanks for all the hard work you put into this project. That said I've run into a wall, and even after parsing issues that appear to be relevant (this issue more specifically) I have not been able to fix this problem.

Setup: So to begin let me briefly explain what I've setup. I have a task running the gphotos-sync on a headless server. It runs every 5 minutes as a CRON task. I have an app on Google setup as per the instructions and it's published (it shows as Status: In Production).

Command: the command I'm running is the following:

$VENV_PATH/bin/python $VENV_PATH/bin/gphotos-sync $TARGET_PATH

Behavior: After exactly 1 hour I see the following error in the logs:

03-04 00:50:01 WARNING  gphotos-sync 3.0.3 2023-03-04 00:50:01.414943 
03-04 00:50:01 WARNING  Indexing Google Photos Files ... 
03-04 00:50:01 ERROR    Request failed with status 401: b'{\n  "error": {\n    "code": 401,\n    "message": "Request had invalid authentication credentials. Expected OAuth 2 access token, login cookie or other valid authentication credential. See https://developers.google.com/identity/sign-in/web/devconsole-project.",\n    "status": "UNAUTHENTICATED"\n  }\n}\n' 
03-04 00:50:01 ERROR    
Process failed. 
Traceback (most recent call last):
  File "/home/henk/venv/lib/python3.10/site-packages/gphotos_sync/Main.py", line 497, in main
    self.start(args)
  File "/home/henk/venv/lib/python3.10/site-packages/gphotos_sync/Main.py", line 437, in start
    self.do_sync(args)
  File "/home/henk/venv/lib/python3.10/site-packages/gphotos_sync/Main.py", line 401, in do_sync
    self.google_photos_idx.index_photos_media()
  File "/home/henk/venv/lib/python3.10/site-packages/gphotos_sync/GooglePhotosIndex.py", line 148, in index_photos_media
    items_json = self.search_media(
  File "/home/henk/venv/lib/python3.10/site-packages/gphotos_sync/GooglePhotosIndex.py", line 135, in search_media
    return self._api.mediaItems.search.execute(body).json()  # type: ignore
  File "/home/henk/venv/lib/python3.10/site-packages/gphotos_sync/restclient.py", line 106, in execute
    result.raise_for_status()
  File "/home/henk/venv/lib/python3.10/site-packages/requests/models.py", line 1021, in raise_for_status
    raise HTTPError(http_error_msg, response=self)
requests.exceptions.HTTPError: 401 Client Error: Unauthorized for url: https://photoslibrary.googleapis.com/v1/mediaItems:search

In order to fix this, I need to manually create a new .gphotos.token on the desktop and upload it to the server. This does allow it to continue as normal for another hour, however once the hour has elapsed the task fails with the 401 seen above. This doesn't seem very practical for what's supposed to be a hands-off solution for this, so what I'm wondering is if I'm missing something about token generation on googles end that would prevent the token from expiring like this?

Another thing to note, I was looking at that .gphotos.token expires-at field, and that appears to show a datetime that's 7 hours after generation, not 1 hour. So I'm wondering what's causing the token to expire as early as it does.

Am I at the mercy of Google here or is there anything I can do to fix this? Thanks for any help you can provide!

[gilesknap]

This sounds as though you did not enable refresh tokens when creating your secret. If you go through these instructions again and create a new secret https://gilesknap.github.io/gphotos-sync/main/tutorials/oauth2.html it should work.

Google have changed things on this quite a few times so report back if any of the steps in that documentation linked don't look right.

[deathtenk]

I wiped the old application and made a new app completely from scratch and followed each step exactly as instructed by the documentation. Nothing about the documentation was off, but the token still expires after exactly 1 hour. Here's what the client_secret.json looks like:

{
  "installed": {
    "client_id": "xxx",
    "project_id": "gphotos-380208",
    "auth_uri": "https://accounts.google.com/o/oauth2/auth",
    "token_uri": "https://oauth2.googleapis.com/token",
    "auth_provider_x509_cert_url": "https://www.googleapis.com/oauth2/v1/certs",
    "client_secret": "xxx",
    "redirect_uris": [
      "http://localhost"
    ]
  }
}

and here's what the .gphotos.token looks like:

{
  "access_token": "xxx",
  "refresh_token": "xxx",
  "token_type": "Bearer",
  "scope": [
    "https://www.googleapis.com/auth/photoslibrary.readonly",
    "https://www.googleapis.com/auth/photoslibrary.sharing"
  ],
  "expires_at": 1678458526.649647
}

here's a screenshot of the app as configured on google:

[gilesknap]

I think the issue is that you have configured a consent screen. This means your app requires review by google.

See my equivalent.

[gilesknap]

Closing as stale. Please re-open if you still want to follow up.

[IslandJohn]

I'm having this issue as well. There doesn't appear to be a "refresh" setting that I can see when creating the client_secret.

I just configured gphotos-sync (locally to get the token), and then the container on a Synology. The token expired after an hour. I went through the client_secret setup again, but there doesn't appears to be a refresh setting. The consent screen shows "Verification not required" and "In production".

Since I didn't create the issue, I can't re-open it, would you prefer a file a new one?

[IslandJohn]

I went through the flow for a 3rd time, and I'm getting the same issue. Token expires after 1 hour of running as a container.

[deathtenk]

Can confirm i was also unable to find a solution to this problem, and I'm aware that that the problem itself is not an issue related to the actual working script and something to do with what's happening on the Google end of things.

[IslandJohn]

I'm digging a bit through the authorization flow and the refresh via OAuth2Session. Reading the docs, it states that it's expected for the token to have an "expires_in" property. Interestingly, the token Google is handing out does NOT have an expires_in property (only expires_at). Could this be the problem? Maybe this is causing the token not to be refreshed.

{"access_token": "...", "refresh_token": "...", "token_type": "Bearer", "scope": ["https://www.googleapis.com/auth/photoslibrary.readonly", "https://www.googleapis.com/auth/photoslibrary.sharing"], "expires_at": 1680065072.562923}

I also fixed a time zone mismatch between the system from where I was getting the token and the container (by setting the TZ environment variable), but this did not resolve the issue, and the token still becomes invalid after exactly 1 hour.

@deathtenk Could you re-open this issue?

[gilesknap]

Reopening. I would like to follow up on the question of configuring a consent screen. I have a strong recollection that this was reported as a cuase of token expiry but I can't find the issue right now.

[IslandJohn]

Here are my setup screens:

[gilesknap]

Thanks @IslandJohn. I'm going to walk through the setup again this weekend and see if I can reproduce the error - will be using your screens as a comparison.

[IslandJohn]

I see now in OAuth lib that expires_at is sufficient and expires_in is actually converted to that property, and compared for expiry all in UTC.

I got a new token with --new-token at 17:00 EDT (21:00 UTC), which came with an expire_at of 1680141610. This is 5 hours from the time of the request, which seems suspicious because it's 1 more than the UTC/TZ difference of 4 hours I'm in. If the tokens are expiring in an hour, the expire_at should have been closer to 1680127200 (18:00EDT/22:00UTC).

UPDATE: I set the TZ environment variable on the system where I'm requesting the token to UTC ... Guess what?

I got a token with the right expiry time of 1 hour. I made the request at 21:23 UTC and got the expire time of 1680128624 which is 22:23 UTC. So this seems to be an issue with time zone conversion somewhere. I'll test to see if this token will refresh (my guess is that it will - and my guess is also that the other token with the incorrect expire_at would also "start" working again after the expiry time since a refresh would be requested).

UPDATE: The token I retrieved using a TZ=UTC worked and is not timing out after the 1 hour period. They continue to be refreshed appropriately.

So this looks like a WORKAROUND: Make sure to "export TZ=UTC" before retrieving you first token. I have also reverted the TZ of the container to UTC.

I haven't dug or thought too deeply, but perhaps the issue is in the Google libraries with the stripping of the time zone:

expiry = datetime.strptime( expiry.rstrip("Z").split(".")[0], "%Y-%m-%dT%H:%M:%S" )

I don't have time right now to keep investigating more, but I filed a bug against google-auth here.

[gilesknap]

@IslandJohn great work, thanks for that.

I'm probably hampered by living in the UK and having my timezone = UTC for half the year - maybe I just lucked out with my tokens as a result.

[deathtenk]

@IslandJohn wow what a bizarre issue. I'm gonna try this and see if the token refreshes correctly on my end.

[gilesknap]

Leaving this open to monitor the state of https://github.com/googleapis/google-auth-library-python/issues/1264 (thanks @IslandJohn !)

Looks from the tags that Google are taking it seriously.

[juzna]

Hey, I just noticed your issue here because I was dealing with another timezone issue the google auth library. I already posted a conclusion on the issue linked above, but let me add the conclusion also here, because I think the bug is in this repo.

The google-auth library internally uses python naive datetime objects and assumes they're all in UTC. This is correct behaviour according to python datetime documentation:

A naive object does not contain enough information to unambiguously locate itself relative to other date/time objects. Whether a naive object represents Coordinated Universal Time (UTC), local time, or time in some other timezone is purely up to the program, just like it is up to the program whether a particular number represents metres, miles, or mass.

One problem is that I haven't found any documentation stating that it's in UTC, so all users of the library would have to read its code to figure it out.

The bug happens in your code when you call expiry.timestamp() here. This messes up the timezone conversion and produces a bad unix timestamp.

[gilesknap]

@juzna thanks for this!

I'm not totally clear what the fix is though. Do I need to copy flow.credentials.expiry.timestamp() into a variable and coerce its timezone before putting it in the token?

[deathtenk]

So I drafted a PR where I localized the timestamp before I put it in the token. I don't know if I got things exactly correct (particularly where I account for DST) but from my understanding of the posts above this is what needs to happen. I'm open to any feedback.

[deathtenk]

nvm, it was incorrect. I misunderstood the issue. still thinking through how to handle this pickle.

[deathtenk]

Basically with a better understanding of the problem I was able to correct it by grabbing the system offset from time.timezone and subtracting it from the expiry. This corrects the problem setting the expiry to exactly an hour from whenever the process started relative to how the system clock is set. Again open to feedback.

[gilesknap]

The PR #435 was merged a while back and is now in release 3.2.0

[IslandJohn]

When do you plan to push an update to Docker Hub?

[gilesknap]

That is supposed to happen automatically, but has not. It looks like my merge of upstream skeleton has broken a few things even though the tests all pass.

Will get back to you on this, but maybe not until the weekend.