Handle 401 response when using installation token shortly after creation

[gr2m]

This is a follow up to octokit/plugin-paginate-rest.js#33

Here is a simplified test case that I run in GitHub Actions.

(async () => {
  for (let index = 0; index < 10000; index++) {
    try {
      const { Octokit } = require("@octokit/core");
      const { createAppAuth } = require("@octokit/auth-app");

      const octokit = new Octokit({
        authStrategy: createAppAuth,
        auth: {
          id: process.env.TEST_APP_ID,
          privateKey: process.env.TEST_APP_PRIVATE_KEY,
          installationId: process.env.TEST_APP_INSTALLATION_ID,
        },
      });

      await octokit.request("GET /installation/repositories", {
        mediaType: {
          previews: ["machine-man"],
        },
      });

      process.stdout.write(".");
    } catch (error) {
      console.log("Error: ", error);
      process.exit(1);
    }
  }

  console.log("");
})();

Here is a run that triggered the expected error:
https://github.com/octokit/sandbox/runs/705154995?check_suite_focus=true#step:5:1

The way this could work

1. Keep track on weather any request was successful
2. If the first request using the installation authentication token fails with 401, log a warning and retry after 1s, then 2s, then 4s. The warning should include an explanation why the delay might be necessary in some cases
3. If a previous request using the same access token was successful, do not retry in case of a 401

I have asked the documentation team to document that behavior so we can reference it from our docs and error messages

/cc @steve-norman-rft @droidpl

[steve-norman-rft]

@gr2m I think I've been seeing this problem in a Probot app as well. Had something running as a test with very little activity happening on it and have seen a few Bad credentials logged when there is nothing actually happening.

I think it is probably the stats page refreshing the popular repositories list at https://github.com/probot/probot/blob/master/src/apps/stats.ts#L57. The log entries are are happening at around the same time past the hour which also corresponds to when the app was last started.

Just another example of something that might be where you've spotted the 401 errors and flagging it for anyone else that sees the problem.

[gr2m]

I am very certain that this problem only applies to GET and HEAD requests, because read-only requests can hit replica of the main database where the newly created installation access token might not have yet propagated to, while all mutating requests hit the main database.

@droidpl can you confirm?

[droidpl]

I would say so, this is what it does on GHES so I believe cloud would do the same at a bigger scale. Read can read from any replica while write goes to the main database and replicates.

[github-actions]

🎉 This issue has been resolved in version 2.4.6 🎉

The release is available on:

• GitHub release
• npm package (@latest dist-tag)

Your semantic-release bot 📦🚀