401 Unauthorized errors every hour

[tommilligan]

Bug Report

https://github.com/tommilligan/prowl-github-app/

Current Behavior
I have a probot app running full time on AWS. The app

• listens for events
• performs some long-running (~2 min) checks
• responds to the GitHub API

Occasionally, I get 401 Unauthorized errors back from the API when performing actions:

HttpError: {"message":"Bad credentials","documentation_url":"https://developer.github.com/v3"}
    at response.text.then.message (/usr/src/app/node_modules/@octokit/rest/lib/request/request.js:78:19)
    at <anonymous>
    at process._tickDomainCallback (internal/process/next_tick.js:228:7)

These errors always happen at the same point in the hour - e.g. for a single instance, at 10:05, 11:05, 14:05 and 21:05.

I suspect this is because in the ~2 min check time, the OAuth token attached to the event context expires. This then results in unauthorized requests when calling context.github. New events are received with valid tokens, which do not error.

Expected behavior/code
Not to get Unauthorized errors sproradically

Environment

• Probot version(s): 7.0.0
• Node/npm version: node 8.9.4/npm 5.6.0
• OS: Ubuntu 18.04.1 LTS

Possible Solution

Requests to either:

• pass first time by always using the latest token
• on Unauthorized, refresh access token and retry

Additional context/Screenshots

                                    |
+-----------------------------------+------------------------+
|                                                            |
| GitHub API                                                 |
|                                                            |
+-+-----+--------^--------------+---+---+---------^----------+
  |     |        |              |   |   |         |
  v     |event   |action        |       v         |
token   |        |(Authorized)  |   | token       |
  +   +-v------------+          |                 |
  +--->   context    |          |   |             |
  |   +--------------+          |                 |action
  |                             |   |             |(Unauthorized)
  |                            +v---+------------------+
  +---------------------------->  context              |
                               +----+------------------+
                                    |

                                    |
                        probot access_token expires
                                    |

                                    |

[tommilligan]

Having read a bit more through Application construction, the simplest fix for me would be to have the installationToken cache ttl customiseable:

probot/src/application.ts

Line 200 in 80fc41a

}, { ttl: 60 * 59 }) // Cache for 1 minute less than GitHub expiry

I would reduce this to ~ 5 min before expiry and it would fix my issues.

[hiimbex]

I'm definitely not opposed to adding an env option here, but I'm wondering what is happening in your app that takes 2 minutes?

performs some long-running (~2 min) checks

We have some pretty complex apps and we've yet to run into this issue. 🤔 I'll jump into the PR now.

[tommilligan]

@hiimbex if you're interested in the actual scenario: one of the things my app does is check whether commit status is success after a CI update. I delay for a short amount of time by default (say 5s) to allow other CI systems to have started running and set pending statuses.

At work we use Concourse CI, which takes significantly longer to start. Unless I delay API actions, there's a window where the commit status has some CI passed, and some CI not started, and would cause incorrect app behaviour.

+---------------------------+
|  new pull request commit  |
+-----+--------------+------+
      |              |
+-----v------+       |
| codeclimate+----------------> pending
|            |       |
|            |       |
|            |       |
|            |       |
|            +----------------> success
+------------+       |
                     |
                     | (don't want to call API here
                     |  as there are unstarted checks)
                     |
                     |
               +-----v------+
               | concourse  +-> pending
               |            |
               |            |
               |            |
               |            |
               |            +-> success
               +------------+

[rthadur]

@tommilligan iam getting this error for every event in Google cloud functions , do you have any solution ?

[tommilligan]

If it's for every event, it sounds like you have bad credentials, or all of your events take longer than an hour to process. If you have a minimal reproducible example I can take a look

[gr2m]

@tommilligan can you check with latest Probot (npm install probot@beta)? We have new thorttling built-in as well as authenticating as installation right before the request, it definitely helped with the problem on WIP

[tommilligan]

@gr2m could you clarify what your request is here? The issue is closed (I merged a PR a while ago), and I haven't experienced this issue since

[gr2m]

All good then, sorry for the noise :) I keep having the "Bad credentials" errors from time to time with the WIP app, and upgrading to Probot 8 beta helped reduce these drastically. So I thought I’d let you know. But if you don’t see them at all anymore then don’t worry about it

[probotbot]

🎉 This issue has been resolved in version 7.1.0 🎉

The release is available on:

• npm package (@release-7.x dist-tag)
• GitHub release

Your semantic-release bot 📦🚀

[gr2m]

@tommilligan the custom INSTALLATION_TOKEN_TTL setting should no longer be required with the Probot v10. Installation access tokens are renewed on demand at the time of the request via https://github.com/octokit/auth-app.js/, they are no longer set statically at the time when an event is handled.

Let me know if you see a problem with removing the environment variable

GitHub

octokit/auth-app.js

GitHub App authentication for JavaScript. Contribute to octokit/auth-app.js development by creating an account on GitHub.

[tommilligan]

Thanks for the update! I don't see any issue with removing the environment variable.

I no longer maintain the app I built (although I hear it's still kicking at my old workplace). Happy to see probot is still actively developed 🙂