staticman: Error on merging github pull request

When I merge (every merge) a pull request generated by my staticman instance hosted on heroku, I receive the following error:

2021-04-22T02:30:20.417355+00:00 heroku[router]: at=info method=POST path="/v1/webhook" host=bmstaticmaninstance.herokuapp.com request_id=569654ed-47b1-4337-a1fd-27260ac51ce2 fwd="140.82.115.246" dyno=web.1 connect=0ms service=18ms status=200 bytes=223 protocol=https
2021-04-22T02:30:27.162232+00:00 app[web.1]: /app/node_modules/@octokit/request/dist-node/index.js:66
2021-04-22T02:30:27.162240+00:00 app[web.1]:         const error = new requestError.RequestError(message, status, {
2021-04-22T02:30:27.162242+00:00 app[web.1]:                       ^
2021-04-22T02:30:27.162243+00:00 app[web.1]: 
2021-04-22T02:30:27.162244+00:00 app[web.1]: RequestError [HttpError]: Reference does not exist
2021-04-22T02:30:27.162244+00:00 app[web.1]:     at /app/node_modules/@octokit/request/dist-node/index.js:66:23
2021-04-22T02:30:27.162244+00:00 app[web.1]:     at processTicksAndRejections (node:internal/process/task_queues:96:5) {
2021-04-22T02:30:27.162245+00:00 app[web.1]:   status: 422,
2021-04-22T02:30:27.162245+00:00 app[web.1]:   headers: {
2021-04-22T02:30:27.162246+00:00 app[web.1]:     'access-control-allow-origin': '*',
2021-04-22T02:30:27.162248+00:00 app[web.1]:     'access-control-expose-headers': 'ETag, Link, Location, Retry-After, X-GitHub-OTP, X-RateLimit-Limit, X-RateLimit-Remaining, X-RateLimit-Used, X-RateLimit-Reset, X-OAuth-Scopes, X-Accepted-OAuth-Scopes, X-Poll-Interval, X-GitHub-Media-Type, Deprecation, Sunset',
2021-04-22T02:30:27.162248+00:00 app[web.1]:     connection: 'close',
2021-04-22T02:30:27.162249+00:00 app[web.1]:     'content-length': '122',
2021-04-22T02:30:27.162249+00:00 app[web.1]:     'content-security-policy': "default-src 'none'",
2021-04-22T02:30:27.162249+00:00 app[web.1]:     'content-type': 'application/json; charset=utf-8',
2021-04-22T02:30:27.162250+00:00 app[web.1]:     date: 'Thu, 22 Apr 2021 02:30:27 GMT',
2021-04-22T02:30:27.162251+00:00 app[web.1]:     'referrer-policy': 'origin-when-cross-origin, strict-origin-when-cross-origin',
2021-04-22T02:30:27.162251+00:00 app[web.1]:     server: 'GitHub.com',
2021-04-22T02:30:27.162252+00:00 app[web.1]:     'strict-transport-security': 'max-age=31536000; includeSubdomains; preload',
2021-04-22T02:30:27.162252+00:00 app[web.1]:     vary: 'Accept-Encoding, Accept, X-Requested-With',
2021-04-22T02:30:27.162253+00:00 app[web.1]:     'x-content-type-options': 'nosniff',
2021-04-22T02:30:27.162253+00:00 app[web.1]:     'x-frame-options': 'deny',
2021-04-22T02:30:27.162254+00:00 app[web.1]:     'x-github-media-type': 'github.v3; format=json',
2021-04-22T02:30:27.162254+00:00 app[web.1]:     'x-github-request-id': '8F8C:0CA8:1C4C94:501EB5:6080DFC3',
2021-04-22T02:30:27.162254+00:00 app[web.1]:     'x-ratelimit-limit': '5000',
2021-04-22T02:30:27.162255+00:00 app[web.1]:     'x-ratelimit-remaining': '4983',
2021-04-22T02:30:27.162255+00:00 app[web.1]:     'x-ratelimit-reset': '1619061787',
2021-04-22T02:30:27.162256+00:00 app[web.1]:     'x-ratelimit-used': '17',
2021-04-22T02:30:27.162256+00:00 app[web.1]:     'x-xss-protection': '0'
2021-04-22T02:30:27.162256+00:00 app[web.1]:   },
2021-04-22T02:30:27.162256+00:00 app[web.1]:   request: {
2021-04-22T02:30:27.162257+00:00 app[web.1]:     method: 'DELETE',
2021-04-22T02:30:27.162258+00:00 app[web.1]:     url: 'https://api.github.com/repos/binarymist/BinaryMistBlog/git/refs/heads/staticman_d1e13160-a311-11eb-9c0b-1f6159366f7a',
2021-04-22T02:30:27.162258+00:00 app[web.1]:     headers: {
2021-04-22T02:30:27.162259+00:00 app[web.1]:       accept: 'application/vnd.github.v3+json',
2021-04-22T02:30:27.162259+00:00 app[web.1]:       'user-agent': 'Staticman octokit.js/16.35.0 Node.js/16.0.0 (Linux 4.4; x64)',
2021-04-22T02:30:27.162260+00:00 app[web.1]:       authorization: 'token [REDACTED]',
2021-04-22T02:30:27.162260+00:00 app[web.1]:       'content-length': 0
2021-04-22T02:30:27.162261+00:00 app[web.1]:     },
2021-04-22T02:30:27.162261+00:00 app[web.1]:     request: {
2021-04-22T02:30:27.162261+00:00 app[web.1]:       timeout: 5000,
2021-04-22T02:30:27.162262+00:00 app[web.1]:       hook: [Function: bound bound register],
2021-04-22T02:30:27.162262+00:00 app[web.1]:       validate: {
2021-04-22T02:30:27.162263+00:00 app[web.1]:         owner: { required: true, type: 'string' },
2021-04-22T02:30:27.162263+00:00 app[web.1]:         ref: { required: true, type: 'string' },
2021-04-22T02:30:27.162263+00:00 app[web.1]:         repo: { required: true, type: 'string' }
2021-04-22T02:30:27.162264+00:00 app[web.1]:       }
2021-04-22T02:30:27.162264+00:00 app[web.1]:     }
2021-04-22T02:30:27.162264+00:00 app[web.1]:   },
2021-04-22T02:30:27.162265+00:00 app[web.1]:   documentation_url: 'https://docs.github.com/rest/reference/git#delete-a-reference'
2021-04-22T02:30:27.162265+00:00 app[web.1]: }
2021-04-22T02:30:27.269456+00:00 heroku[web.1]: Process exited with status 1
2021-04-22T02:30:27.342460+00:00 heroku[web.1]: State changed from up to crashed

Sometimes the staticman instance is automatically restarted, if this is the case, subscribers will get notifications, if the staticman instnce isn’t restarted subscribers won’t get notifications. When the next comment is posted the user gets the following error:

image

and the logs say:

2021-04-22T03:05:50.754634+00:00 heroku[router]: at=error code=H10 desc="App crashed" method=POST path="/v3/entry/github/binarymist/BinaryMistBlog/master/comments" host=bmstaticmaninstance.herokuapp.com request_id=4496c735-dcfe-4558-98cb-4ffc10c25c39 fwd="201.118.135.64" dyno= connect= service= status=503 bytes= protocol=https
2021-04-22T03:05:51.682540+00:00 heroku[router]: at=error code=H10 desc="App crashed" method=GET path="/favicon.ico" host=bmstaticmaninstance.herokuapp.com request_id=4b93fafb-4cfe-4514-8408-80666220662c fwd="201.118.135.64" dyno= connect= service= status=503 bytes= protocol=https

and the post of the comment fails. After this every request receives seems to fail

Then I have to restart dyno manually, then I get:

2021-04-22T03:13:34.164644+00:00 heroku[web.1]: State changed from crashed to starting
2021-04-22T03:13:40.005441+00:00 heroku[web.1]: Starting process with command `npm start`
2021-04-22T03:13:42.814789+00:00 app[web.1]: 
2021-04-22T03:13:42.814814+00:00 app[web.1]: > staticman@3.0.0 prestart
2021-04-22T03:13:42.814814+00:00 app[web.1]: > if [ ! -d node_modules ]; then npm install; fi
2021-04-22T03:13:42.814815+00:00 app[web.1]: 
2021-04-22T03:13:42.829369+00:00 app[web.1]: 
2021-04-22T03:13:42.829371+00:00 app[web.1]: > staticman@3.0.0 start
2021-04-22T03:13:42.829371+00:00 app[web.1]: > node index.js
2021-04-22T03:13:42.829371+00:00 app[web.1]: 
2021-04-22T03:13:44.185541+00:00 app[web.1]: Staticman API running on port 38873
2021-04-22T03:13:44.739539+00:00 heroku[web.1]: State changed from starting to up

Now… I remember I had the next problem last time staticman was working, and it’s still happening. When two comment posters subscribe to notifications, there on after on every merge of comment to the github repo, two notifications are sent to each subscribed user. This of course multiplies as the number of subscribed users goes up. Once we have four subscribers, each one of them receives 4 email messages that a new comment has been posted when I merge a comment pull request.

Any idea what’s causing these issues?

The first one I haven’t noticed befroe as I used to use the community provided staticman instance. Now that I’m using my own instance, I get to see the logs.

The second one is a long standing issue, #182

Am I perhaps missing a value or values from the api config?
All I have in Heroku is the following populated values (all detailed in the getting started guide):

GITHUB_APP_ID
GITHUB_PRIVATE_KEY
RSA_PRIVATE_KEY

My site configuration file (staticman.yml) is here.

There are no issues with my front-end, it’s been good for years, examples:

Thanks.

About this issue

  • Original URL
  • State: open
  • Created 3 years ago
  • Reactions: 1
  • Comments: 16 (6 by maintainers)

Most upvoted comments

@andsplat Thank you! I had the double hook as well. Have been racking my brain!

@binarymist I might have fixed this. I blame the lack of instructions for implementing Staticman. If you are like me, I had to piece together instructions from a lot of different sources to get it to work (and some were using v2 versus v3 and GitHub application vs separate GitHub account, etc.).

In the end, I noticed I had two webhooks running. One on the repo and one in my GitHub App. It seems what was happening is that when I merged or closed a pull request, one of the webhooks acted first, which is why my comments were still working (ie: able to be posted to my blog), but when the second webhook tried to delete the branch, it got an error since the branch/file were already deleted. This resulted in my Heroku Staticman app crashing. I removed the webhook from my repo (just keeping the one in the GitHub App) and now I am not seeing the errors.

Hopefully this will work for you and others!