Dropbox: token expiring and not being refreshed

Thanks! I created a Dropbox App and tried it that way. Same result.

From reading the documentation while I was creating the permissions, it looks like Dropbox used to usetokens that never expired. Then they implemented refreshing access tokens. They allowed the old-style tokens for a transition time, but it looks like they have ended that transition time.

So I think the only way to use a token longer than 4 hours will be to refresh it when it expires.

There was an Access token expiration option with which you can select long-lived tokens but now that option is gone.

I’ll work on a new version that can refresh the token.

1 Like

Thank you for working on the refresh-token feature, much appreciated! I will be happy to test it out if you need a volunteer.

I tried to use Dropbox today and have the same troubles. So is there any update on this topic?

Never mind, I switched to IDrive e2 and it seems like the best file storage for now (for me).

The change to support Dropbox refresh token has been checked in: Use long-lived refresh token for the Dropbox backend · gilbertchen/duplicacy@cde660e · GitHub

You can get your refresh token from https://duplicacy.com/dropbox_start

Where do we use this refresh token? When creating the Dropbox storage it asks us for the access token, which expires after a while. Using the refresh token as access token also doesn’t work so I’m not sure how to use it?

Thanks

Hey @gchen,

I used Dropbox for Duplicacy to grab a new token and noticed my backups are failing after some time with errors that look like this:

POST https://api.dropboxapi.com/2/files/get_metadata returned 401; refreshing access token%!(EXTRA float64=3.796875)
POST https://api.dropboxapi.com/2/files/get_metadata returned 401; refreshing access token%!(EXTRA float64=3.796875)
POST https://api.dropboxapi.com/2/files/get_metadata returned 401; refreshing access token%!(EXTRA float64=5.6953125)
POST https://api.dropboxapi.com/2/files/get_metadata returned 401; refreshing access token%!(EXTRA float64=1.6875)
POST https://api.dropboxapi.com/2/files/get_metadata returned 401; refreshing access token%!(EXTRA float64=0.75)
POST https://api.dropboxapi.com/2/files/get_metadata returned 401; refreshing access token%!(EXTRA float64=1.6875)
...

Those just repeat forever. Given that 401 is an authorization error I took a look at the HTML for that dropbox_start page you have. The post for getting a token looks like this:

<div class="row">
          <form action="https://www.dropbox.com/1/oauth2/authorize" method="get">
              <input type="hidden" name="response_type" value="token"/>
              <input type="hidden" name="client_id" value="vp00fqqtagpzk0l"/>
              <input type="hidden" name="redirect_uri" value="https://duplicacy.com/dropbox_token.html"/>
              <button type="submit" class="btn btn-lg btn-primary center-block">Continue</button>
       </div>

This isn’t causing a problem, but just a note that you’re missing a </form> tag in there. :slight_smile:

But, I think the problem here is that you’re requesting a regular token still here and not making a request for offline access so that you can also get a refresh token. If you look in the oauth guide for dropbox here it talks about how to get a refresh token: Dropbox OAuth Guide - Dropbox. You need to use response_type of code instead of token and you need to add another parameter of token_access_type set to offline.

So, like this instead:

<div class="row">
          <form action="https://www.dropbox.com/1/oauth2/authorize" method="get">
              <input type="hidden" name="response_type" value="code"/>
              <input type="hidden" name="token_access_type" value="offline"/>
              <input type="hidden" name="client_id" value="vp00fqqtagpzk0l"/>
              <input type="hidden" name="redirect_uri" value="https://duplicacy.com/dropbox_token.html"/>
              <button type="submit" class="btn btn-lg btn-primary center-block">Continue</button>
          </form>
       </div>

This changes the oauth flow to use a code flow instead of a direct token flow though. They only allow the code flow for getting a refresh token. So, you need a few more changes for the redirect page unfortunately. Using the code flow for oauth you’re going to get an authorization code which you then have to use to hit https://www.dropbox.com/1/oauth2/token with a grant_type=authorization_code parameter. That will give you the final short lived access_token and long lived refresh_token which we can then plop into the duplicacy app. I’m assuming that the code in duplicacy is hitting oauth2/token with the refresh token and the grant_type=refresh_token already (didn’t check that). If not…that’s also required.

I’m not sure if your webpage code is accessible from your github repo, but if so I’d be happy to send you a PR if you can point me to where the files are. Also, I can check on the refresh and update that as well if necessary. Would appreciate a pointer to the file where the refresh call is made too though since I don’t know the code base well. :slight_smile:

Actually, I found where the dropbox client code is the separate repository. Based on that code it must be a refresh token I’ve got else you’d never be able to get the initial access token (still not sure how that page returned a refresh token, but /shrug). So, it’s got to be a problem with refreshing the token during a backup when a 401 is returned.

The log statement I see repeated forever looks like it’s from client.go on line 126. Which is right before refreshToken is called on the client. err appears to be nil from there else there would be another different log statement, which there’s not. The only two ways I can see not getting a new token from there is if client.Token.Valid() returns true still for the non-working token or if the http call to the refresh page (which looks like it’s your own page) is returning a token still, but it’s not refreshed. In the former case it would spin refreshing forever without actually refreshing. But, that Token looks like it’s a standard Go oauth2 library token which I’m guessing should be working.

I’ll try playing around with that library to see if I can repro the issue outside of duplicacy.

@gchen,

It looks like the issue is in your refresh endpoint on duplicacy.com. Here’s a minimal example to repro the issue. Though you have to leave it running for > 4hrs. :stuck_out_tongue: Excuse my crappy go code…haven’t written basically anything in Go before.

package main

import (
  "fmt"
  "os"
  "time"
  "github.com/gilbertchen/go-dropbox"
)

func main() {
  if len(os.Args) < 2 {
    fmt.Printf("\nUsage: %s REFRESH_TOKEN DO_FIX\n\n  REFRESH_TOKEN: Your refresh token\n  DO_FIX: true if you want to try the fix else blank to run as duplicacy does refresh.\n\n", os.Args[0])
    os.Exit(1)
  }
  var refreshToken = os.Args[1]

  // Create a client same way as in duplicacy_dropboxstorage.go
  client := dropbox.NewFiles(dropbox.NewConfig("", refreshToken, "https://duplicacy.com/dropbox_refresh"))

  lastToken := client.Token
  iter := 0

  for {
    fmt.Printf("[%s]: Running iteration %d\n", time.Now().String(), iter)

    iter += 1

    // Make a request just to have go-dropbox create the access token.
    input := &dropbox.ListFolderInput{
      Path: "/",
      Recursive: false,
      IncludeMediaInfo: false,
      IncludeDeleted: false,
    }

    _, err := client.ListFolder(input)

    if err != nil {
      fmt.Printf("Error! %+v\n", err)
    }

    if client.Token.AccessToken != lastToken.AccessToken {
      lastToken = client.Token

      fmt.Printf("Token changed at %s\n", time.Now().String())

      // Write out some debugging showing the token...
      fmt.Printf("Token: %+v\n", client.Client.Token)
    }

    if !client.Client.Token.Valid() {
      fmt.Printf("Token is NOT valid.\n")

      // Write out some debugging showing the token...
      fmt.Printf("Token: %+v\n", client.Client.Token)
    }

    time.Sleep(5 * time.Second)
  }
}

This yields this after the access token expires (I’ve redacted my refresh and access tokens):

[2022-11-25 23:58:49.926520839 -0500 EST m=+0.000501734]: Running iteration 0
Token changed at 2022-11-25 23:58:50.628571718 -0500 EST m=+0.702552613
Token: {AccessToken:<REDACTED> TokenType:bearer RefreshToken:<REDACTED> Expiry:2022-11-26 08:58:50.207224835 +0000 UTC raw:<nil>}              100% 6608KB  11.0MB/s   00:00
[2022-11-25 23:58:55.630222593 -0500 EST m=+5.704203489]: Running iteration 1
[2022-11-25 23:59:00.822184954 -0500 EST m=+10.896165845]: Running iteration 2
[2022-11-25 23:59:06.002938476 -0500 EST m=+16.076919386]: Running iteration 3
[2022-11-25 23:59:11.262870557 -0500 EST m=+21.336851451]: Running iteration 4

...

[2022-11-26 03:58:26.470811855 -0500 EST m=+14376.544792756]: Running iteration 2645
[2022-11-26 03:58:31.656991023 -0500 EST m=+14381.730971915]: Running iteration 2646
[2022-11-26 03:58:36.842373916 -0500 EST m=+14386.916354811]: Running iteration 2647
[2022-11-26 03:58:42.035193941 -0500 EST m=+14392.109174848]: Running iteration 2648
Token is NOT valid.
Token: {AccessToken:<REDACTED> TokenType:bearer RefreshToken:<REDACTED> Expiry:2022-11-26 08:58:50.207224835 +0000 UTC raw:<nil>}
[2022-11-26 03:58:47.222186559 -0500 EST m=+14397.296167454]: Running iteration 2649
Token is NOT valid.
Token: {AccessToken:<REDACTED> TokenType:bearer RefreshToken:<REDACTED> Expiry:2022-11-26 08:58:50.207224835 +0000 UTC raw:<nil>}
[2022-11-26 03:58:52.401880041 -0500 EST m=+14402.475860948]: Running iteration 2650
2022/11/26 03:58:52 [DROPBOX_RETRY] POST https://api.dropboxapi.com/2/files/list_folder returned 401; refreshing access
token%!(EXTRA float64=0.5)
2022/11/26 03:58:52 [DROPBOX_RETRY] POST https://api.dropboxapi.com/2/files/list_folder returned 401; refreshing access
token%!(EXTRA float64=0.5)
2022/11/26 03:58:53 [DROPBOX_RETRY] POST https://api.dropboxapi.com/2/files/list_folder returned 401; refreshing access
token%!(EXTRA float64=0.5)

From the logs you can see from the Expiry, the access token didn’t actually change after the refresh. I verified that just setting client.Token.AccessToken to "" before setting the body for the refresh call allows your refresh endpoint to properly refresh the endpoint. Not sure what you’re doing on that refresh page, but if you’re just checking for the existence of AccessToken instead of checking if the Expiry is in the past then it would explain this behavior.

You can fix it with a one line change too the go-dropbox code to set client.Token.AccessToken to "" as I mentioned above. Or, if you don’t want to do a new duplicacy version, just update that refresh page to check Expiry and make sure to refresh if it’s in the past.

I’ll make a PR on go-dropbox, but if you can fix the refresh page it wouldn’t require an update for everyone hitting the issue which would be nice. Also…you could just use the dropbox refresh endpoint instead though you’d have to change what you send a little.

UPDATE: Here’s the PR: Fix refreshing access token after expiration by stuckj · Pull Request #4 · gilbertchen/go-dropbox · GitHub

I updated the duplicacy.com/dropbox_refresh api to clear the AccessToken as you suggested. Can you run the test again?

Sure thing. I’ll run it again tonight and check it tomorrow.

Nope, same problem. You’re sure the endpoint is clearing the token before doing whatever you normally do for refresh in there?

When I verified that worked I just literally ran the same code you have in go-dropbox for refreshing the access token in the for loop a few times and saw it gave a new token each time. But, just to make absolutely sure it works I’ll modify the go-dropbox code locally to clear the token when refreshing and run it for another 4 hrs. But, I’m pretty certain it should work.

UPDATE:

I’m still seeing the same problem with that fix. The logs are interesting though. From what I’m seeing, it looks like it’s stuck in your for loop in the do method. Once it gets into the repeated [DROPBOX_RETRY] calls it stops logging my iteration log methods from the test app. I also put a debug log message in the refreshToken method and I only see that once. So…it’s a little strange. I would expect it would continually call refreshToken from the loop, but I should see the log message each time and I’m not.

One thing I do see wrong though is that after refreshToken is called the header doesn’t get updated for the failed call with the new bearer token. So, it’s going to just keep failing. I’ll see if I can make a fix to update that and give it another try.

Just going to add this right after the err = c.refreshToken() line in your do method to reset the authorization header with the new bearer token.

req.Header.Set("Authorization", "Bearer "+c.AccessToken)

I’ll check back in another 4 hrs. :stuck_out_tongue:

Success! I updated the pull request: Fix refreshing access token after expiration by stuckj · Pull Request #4 · gilbertchen/go-dropbox · GitHub.

So, there were two issues. One was that the access token didn’t update if it wasn’t cleared before refreshing. And the second was that the auth header in the request that failed wasn’t updated after refreshing the token. So, it just repeatedly made the same call with the old access token in a tight loop leading to the repeated log messages. I only see the temp debugging log statement I added in refreshToken once because the client’s AccessToken property WAS reset and the Expiry time has it as now valid. So, refreshToken jumps out early because the token is valid. My log statement was after that. The token just wasn’t used in the API call.

The changes from the PR fixed it in the test script I wrote above. It’ll need a new duplicacy build though.

1 Like

I can confirm that it is working now. A backup job of 10 hours ran to completion successfully. Thank you for the fix!

1 Like

No problem! Glad I could help.

Are you planning on putting out a new release with this fix soon? If so I can just wait for it otherwise I’ll just make my own build.

For now I’m just building my own version of the client to use for backups. Hope you’ll put out a new version at some point though. :slight_smile:

Thanks for making such an awesome backup tool!

I’ll make a new CLI release next week.

1 Like

Will there be also Web UI release with this fix? Possibly also fixing the whole access token issue here: Duplicacy Web Dropbox Issue - #22 by saspus

1 Like

Is there any update on this issue? Any information from @gchen at all?

I think you just need to use the latest CLI in the web UI to get the fix. The issue was in the CLI which is what the web UI uses under the hood.