`v1.6.1` (#290) broke auto-merging (`--pr-merge`)

[MPV]

Hi, I had automerge working before:

• https://github.com/dailymotion-oss/octopilot/releases/tag/v1.6.1
• https://github.com/dailymotion-oss/octopilot/issues/290

...but after upgrading, it doesn't work anymore for me.

cc @jashandeep-sohi (author of #290) for info.

I'll see if I can get back with some more details. It's hard without sharing too much internal details, as you might envision.

[MPV]

Fingers crossed that this one helps instead, looking forward to it: 🤞

• https://github.com/dailymotion-oss/octopilot/pull/292

[vbehar]

thanks for the report. If you can provide some logs it will help us find the root cause.

[MPV]

Logs using v1.6.1:

time="2023-12-08T08:31:37Z" level=debug msg="Updaters ready" updaters="..."
time="2023-12-08T08:31:37Z" level=debug msg="Repositories ready" repositories="..."
time="2023-12-08T08:31:37Z" level=debug msg="Using 'reset' strategy" repository=my-org/repo3
time="2023-12-08T08:31:37Z" level=debug msg="Using 'reset' strategy" repository=my-org/repo7
time="2023-12-08T08:31:37Z" level=debug msg="Using 'reset' strategy" repository=my-org/repo4
time="2023-12-08T08:31:37Z" level=debug msg="Using 'reset' strategy" repository=my-org/repo9
time="2023-12-08T08:31:37Z" level=debug msg="Using 'reset' strategy" repository=my-org/repo5
time="2023-12-08T08:31:37Z" level=debug msg="Using 'reset' strategy" repository=my-org/repo1
time="2023-12-08T08:31:37Z" level=debug msg="Using 'reset' strategy" repository=my-org/repo6
time="2023-12-08T08:31:37Z" level=debug msg="Using 'reset' strategy" repository=my-org/repo8
time="2023-12-08T08:31:37Z" level=debug msg="Using 'reset' strategy" repository=my-org/repo2
time="2023-12-08T08:31:38Z" level=debug msg="Git repository cloned" git-reference=HEAD git-url="https://github.com/my-org/repo1.git" local-path=/tmp/octopilot3067760575/my-org/repo1
time="2023-12-08T08:31:38Z" level=debug msg="Git repository cloned" git-reference=HEAD git-url="https://github.com/my-org/repo2.git" local-path=/tmp/octopilot3067760575/my-org/repo2
time="2023-12-08T08:31:38Z" level=debug msg="Git repository cloned" git-reference=HEAD git-url="https://github.com/my-org/repo3.git" local-path=/tmp/octopilot3067760575/my-org/repo3
time="2023-12-08T08:31:38Z" level=debug msg="Git repository cloned" git-reference=HEAD git-url="https://github.com/my-org/repo4.git" local-path=/tmp/octopilot3067760575/my-org/repo4
time="2023-12-08T08:31:38Z" level=debug msg="Git repository cloned" git-reference=HEAD git-url="https://github.com/my-org/repo5.git" local-path=/tmp/octopilot3067760575/my-org/repo5
time="2023-12-08T08:31:38Z" level=debug msg="Git repository cloned" git-reference=HEAD git-url="https://github.com/my-org/repo6.git" local-path=/tmp/octopilot3067760575/my-org/repo6
time="2023-12-08T08:31:38Z" level=debug msg="Git repository cloned" git-reference=HEAD git-url="https://github.com/my-org/repo7.git" local-path=/tmp/octopilot3067760575/my-org/repo7
time="2023-12-08T08:31:38Z" level=debug msg="No existing Pull Request found" labels="[HAWK-1546 octopilot-update my-workflows]" repository=my-org/repo2
time="2023-12-08T08:31:38Z" level=debug msg="Switched Git branch" branch=octopilot-clpd8qifo2rr7vbg4470 repository-name=repo2
time="2023-12-08T08:31:38Z" level=debug msg="Updater finished" changes=true repository=my-org/repo2 updater="Exec[cmd=sh,args=[-c mkdir -p .github/workflows]]"
time="2023-12-08T08:31:38Z" level=debug msg="Updater finished" changes=true repository=my-org/repo2 updater="Exec[cmd=sh,args=[-c cp /home/runner/work/my-workflows/my-workflows/my-workflows/examples/some-lib.yml .github/workflows/dependencies.yml]]"
time="2023-12-08T08:39:48Z" level=debug msg="Pull Request is not mergeable yet" mergeable-state=blocked pull-request="https://github.com/my-org/repo7/pull/20" repository=my-org/repo7
time="2023-12-08T08:39:48Z" level=debug msg="Pull Request is not mergeable yet" mergeable-state=blocked pull-request="https://github.com/my-org/repo3/pull/85" repository=my-org/repo3
time="2023-12-08T08:40:16Z" level=debug msg="Pull Request is not mergeable yet" mergeable-state=blocked pull-request="https://github.com/my-org/repo2/pull/3" repository=my-org/repo2
time="2023-12-08T08:40:17Z" level=debug msg="Pull Request is not mergeable yet" mergeable-state=blocked pull-request="https://github.com/my-org/repo8/pull/8" repository=my-org/repo8
time="2023-12-08T08:40:17Z" level=debug msg="Pull Request is not mergeable yet" mergeable-state=blocked pull-request="https://github.com/my-org/repo1/pull/4" repository=my-org/repo1
time="2023-12-08T08:40:17Z" level=debug msg="Pull Request is not mergeable yet" mergeable-state=blocked pull-request="https://github.com/my-org/repo6/pull/44" repository=my-org/repo6
time="2023-12-08T08:40:18Z" level=debug msg="Pull Request is not mergeable yet" mergeable-state=blocked pull-request="https://github.com/my-org/repo7/pull/20" repository=my-org/repo7
time="2023-12-08T08:40:18Z" level=debug msg="Pull Request is not mergeable yet" mergeable-state=blocked pull-request="https://github.com/my-org/repo3/pull/85" repository=my-org/repo3
time="2023-12-08T08:40:47Z" level=debug msg="Pull Request is not mergeable yet" mergeable-state=blocked pull-request="https://github.com/my-org/repo2/pull/3" repository=my-org/repo2
time="2023-12-08T08:40:47Z" level=debug msg="Pull Request is not mergeable yet" mergeable-state=blocked pull-request="https://github.com/my-org/repo8/pull/8" repository=my-org/repo8
time="2023-12-08T08:40:47Z" level=debug msg="Pull Request is not mergeable yet" mergeable-state=blocked pull-request="https://github.com/my-org/repo1/pull/4" repository=my-org/repo1
time="2023-12-08T08:40:48Z" level=debug msg="Pull Request is not mergeable yet" mergeable-state=blocked pull-request="https://github.com/my-org/repo6/pull/44" repository=my-org/repo6
time="2023-12-08T08:40:48Z" level=debug msg="Pull Request is not mergeable yet" mergeable-state=blocked pull-request="https://github.com/my-org/repo7/pull/20" repository=my-org/repo7
time="2023-12-08T08:40:49Z" level=debug msg="Pull Request is not mergeable yet" mergeable-state=blocked pull-request="https://github.com/my-org/repo3/pull/85" repository=my-org/repo3
time="2023-12-08T08:41:17Z" level=debug msg="Pull Request is not mergeable yet" mergeable-state=blocked pull-request="https://github.com/my-org/repo2/pull/3" repository=my-org/repo2
time="2023-12-08T08:41:17Z" level=debug msg="Pull Request is not mergeable yet" mergeable-state=blocked pull-request="https://github.com/my-org/repo8/pull/8" repository=my-org/repo8
time="2023-12-08T08:41:17Z" level=debug msg="Pull Request is not mergeable yet" mergeable-state=blocked pull-request="https://github.com/my-org/repo1/pull/4" repository=my-org/repo1
time="2023-12-08T08:41:18Z" level=debug msg="Pull Request is not mergeable yet" mergeable-state=blocked pull-request="https://github.com/my-org/repo6/pull/44" repository=my-org/repo6
time="2023-12-08T08:41:19Z" level=debug msg="Pull Request is not mergeable yet" mergeable-state=blocked pull-request="https://github.com/my-org/repo7/pull/20" repository=my-org/repo7
time="2023-12-08T08:41:19Z" level=debug msg="Pull Request is not mergeable yet" mergeable-state=blocked pull-request="https://github.com/my-org/repo3/pull/85" repository=my-org/repo3
time="2023-12-08T08:41:47Z" level=error msg="Repository update failed" error="failed to merge Pull Request https://github.com/my-org/repo2/pull/3: failed to wait until Pull Request https://github.com/my-org/repo2/pull/3 is mergeable: timeout after 10m0s waiting for Pull Request https://github.com/my-org/repo2/pull/3 mergeable status" repository=my-org/repo2
time="2023-12-08T08:41:48Z" level=error msg="Repository update failed" error="failed to merge Pull Request https://github.com/my-org/repo8/pull/8: failed to wait until Pull Request https://github.com/my-org/repo8/pull/8 is mergeable: timeout after 10m0s waiting for Pull Request https://github.com/my-org/repo8/pull/8 mergeable status" repository=my-org/repo8
time="2023-12-08T08:41:48Z" level=error msg="Repository update failed" error="failed to merge Pull Request https://github.com/my-org/repo1/pull/4: failed to wait until Pull Request https://github.com/my-org/repo1/pull/4 is mergeable: timeout after 10m0s waiting for Pull Request https://github.com/my-org/repo1/pull/4 mergeable status" repository=my-org/repo1
time="2023-12-08T08:41:48Z" level=error msg="Repository update failed" error="failed to merge Pull Request https://github.com/my-org/repo6/pull/44: failed to wait until Pull Request https://github.com/my-org/repo6/pull/44 is mergeable: timeout after 10m0s waiting for Pull Request https://github.com/my-org/repo6/pull/44 mergeable status" repository=my-org/repo6
time="2023-12-08T08:41:49Z" level=error msg="Repository update failed" error="failed to merge Pull Request https://github.com/my-org/repo7/pull/20: failed to wait until Pull Request https://github.com/my-org/repo7/pull/20 is mergeable: timeout after 10m0s waiting for Pull Request https://github.com/my-org/repo7/pull/20 mergeable status" repository=my-org/repo7
time="2023-12-08T08:41:50Z" level=error msg="Repository update failed" error="failed to merge Pull Request https://github.com/my-org/repo3/pull/85: failed to wait until Pull Request https://github.com/my-org/repo3/pull/85 is mergeable: timeout after 10m0s waiting for Pull Request https://github.com/my-org/repo3/pull/85 mergeable status" repository=my-org/repo3
time="2023-12-08T08:41:50Z" level=info msg="Updates finished" repositories-count=9
time="2023-12-08T08:41:50Z" level=fatal msg="Some repository updates failed"

[MPV]

Logs using v1.5.5:

time="2023-12-11T08:28:52Z" level=debug msg="Updaters ready" updaters="..."
time="2023-12-11T08:28:52Z" level=debug msg="Repositories ready" repositories="..."
time="2023-12-11T08:28:52Z" level=debug msg="Using 'reset' strategy" repository=my-org/repo1
time="2023-12-11T08:28:52Z" level=debug msg="Using 'reset' strategy" repository=my-org/repo2
time="2023-12-11T08:28:52Z" level=debug msg="Using 'reset' strategy" repository=my-org/repo3
time="2023-12-11T08:28:52Z" level=debug msg="Using 'reset' strategy" repository=my-org/repo4
time="2023-12-11T08:28:52Z" level=debug msg="Using 'reset' strategy" repository=my-org/repo5
time="2023-12-11T08:28:52Z" level=debug msg="Using 'reset' strategy" repository=my-org/repo6
time="2023-12-11T08:28:52Z" level=debug msg="Using 'reset' strategy" repository=my-org/repo7
time="2023-12-11T08:28:52Z" level=debug msg="Using 'reset' strategy" repository=my-org/repo8
time="2023-12-11T08:28:52Z" level=debug msg="Git repository cloned" git-reference=HEAD git-url="https://github.com/my-org/repo6.git" local-path=/tmp/octopilot1309601579/my-org/repo6
time="2023-12-11T08:28:55Z" level=debug msg="No labels to add to the Pull Request" pull-request="https://github.com/my-org/repo1/pull/20" repository=my-org/repo1
time="2023-12-11T08:28:55Z" level=debug msg="No comments to add to the Pull Request" pull-request="https://github.com/my-org/repo1/pull/20" repository=my-org/repo1
time="2023-12-11T08:28:55Z" level=debug msg="Pull Request mergeable status is not available yet" mergeable-state=unknown pull-request="https://github.com/my-org/repo7/pull/8" repository=my-org/repo7
time="2023-12-11T08:28:55Z" level=debug msg="Pull Request mergeable status is not available yet" mergeable-state=unknown pull-request="https://github.com/my-org/repo5/pull/4" repository=my-org/repo5
time="2023-12-11T08:28:55Z" level=debug msg="Pull Request mergeable status is not available yet" mergeable-state=unknown pull-request="https://github.com/my-org/repo1/pull/20" repository=my-org/repo1
time="2023-12-11T08:28:55Z" level=debug msg="Pull Request mergeable status is not available yet" mergeable-state=unknown pull-request="https://github.com/my-org/repo6/pull/44" repository=my-org/repo6
time="2023-12-11T08:29:25Z" level=debug msg="Pull Request is mergeable" pull-request="https://github.com/my-org/repo8/pull/3" repository=my-org/repo8
time="2023-12-11T08:29:25Z" level=debug msg="Pull Request is mergeable" pull-request="https://github.com/my-org/repo5/pull/4" repository=my-org/repo5
time="2023-12-11T08:29:25Z" level=debug msg="Pull Request is mergeable" pull-request="https://github.com/my-org/repo7/pull/8" repository=my-org/repo7
time="2023-12-11T08:29:25Z" level=debug msg="Pull Request can be merged" pull-request="https://github.com/my-org/repo8/pull/3" repository=my-org/repo8
time="2023-12-11T08:29:25Z" level=debug msg="Pull Request is mergeable" pull-request="https://github.com/my-org/repo6/pull/44" repository=my-org/repo6
time="2023-12-11T08:29:25Z" level=debug msg="Pull Request is mergeable" pull-request="https://github.com/my-org/repo1/pull/20" repository=my-org/repo1
time="2023-12-11T08:29:25Z" level=debug msg="Pull Request can be merged" pull-request="https://github.com/my-org/repo7/pull/8" repository=my-org/repo7
time="2023-12-11T08:29:25Z" level=debug msg="Pull Request can be merged" pull-request="https://github.com/my-org/repo5/pull/4" repository=my-org/repo5
time="2023-12-11T08:29:25Z" level=debug msg="Pull Request can be merged" pull-request="https://github.com/my-org/repo1/pull/20" repository=my-org/repo1
time="2023-12-11T08:29:25Z" level=debug msg="Pull Request can be merged" pull-request="https://github.com/my-org/repo6/pull/44" repository=my-org/repo6
time="2023-12-11T08:29:26Z" level=error msg="Repository update failed" error="failed to merge Pull Request https://github.com/my-org/repo1/pull/20: failed to merge Pull Request https://github.com/my-org/repo1/pull/20: PUT https://api.github.com/repos/my-org/repo1/pulls/20/merge: 405 Merge commits are not allowed on this repository. []" repository=my-org/repo1
time="2023-12-11T08:29:27Z" level=info msg="Pull Request merged" pull-request="https://github.com/my-org/repo8/pull/3" repository=my-org/repo8 retry=0
time="2023-12-11T08:29:27Z" level=info msg="Repository update finished" repository=my-org/repo8
time="2023-12-11T08:29:27Z" level=info msg="Pull Request merged" pull-request="https://github.com/my-org/repo5/pull/4" repository=my-org/repo5 retry=0
time="2023-12-11T08:29:27Z" level=info msg="Repository update finished" repository=my-org/repo5
time="2023-12-11T08:29:27Z" level=info msg="Pull Request merged" pull-request="https://github.com/my-org/repo7/pull/8" repository=my-org/repo7 retry=0
time="2023-12-11T08:29:27Z" level=info msg="Repository update finished" repository=my-org/repo7
time="2023-12-11T08:29:28Z" level=info msg="Pull Request merged" pull-request="https://github.com/my-org/repo6/pull/44" repository=my-org/repo6 retry=0
time="2023-12-11T08:29:28Z" level=info msg="Repository update finished" repository=my-org/repo6
time="2023-12-11T08:39:00Z" level=info msg="Updates finished" repositories-count=9

[jashandeep-sohi]

Do you have any other branch protection rules enabled? For example, Require signed commits or Require approvals?

[MPV]

Do you have any other branch protection rules enabled? For example, Require signed commits or Require approvals?

Yes but it's a bit of a mix here with different repos having different rules (sorry, can try to look up specific examples), but one repo I know stopped working in v1.6.1 had:

1. No repo-level branch protection.
2. No repo-level rulesets.
3. An org-level ruleset requiring PRs before merge.
4. An org-level ruleset requiring approval before merge.

...and then a bunch of repos with different kinds of repo-level branch protection, such as:

• approvals from codeowners
• specific checks
• ...

[jashandeep-sohi]

So, that might be why it's stuck waiting in mergable-state=blocked. While it's waiting, does the UI show the PR as "green" and mergable?

I suppose my patch wasn't backwards compatible because it also checks for other branch protection rules implicitly, in addition to the status checks. But this does feel like it's the correct thing to do. IMO, if you have branch protection rules, they should be followed by octopilot. But I can also see the need for side-stepping them when you're batch updating hundreds of repos. But then the question arises what do you want to side-step? Everything or the just the approvals or commit signature checks, etc. When it's done through the UI, it's relatively easy to make that decision, but it's tricky doing it via the API because that information is not readily available.

I don't know what the best solution is, but to maintain backwards compatibility maybe we add the old "status API check method" back in, make it the default, and then this new behavior is exposed with yet another flag. That would mean then there are three different ways of doing a PR merge (--pr-merge-auto being the other one). Which might be confusing.

[MPV]

So, that might be why it's stuck waiting in mergable-state=blocked. While it's waiting, does the UI show the PR as "green" and mergable?

Yes they do (but just for admins, which my app for Octopilot is):

[jashandeep-sohi]

Yes they do (but just for admins, which my app for Octopilot is):

"Merging is blocked" is what I'm referring to. The mergeable_state field in the API is reporting the same thing, and my changes made octopilot wait until that's in a clean state. That can only happen once all branch protection rules/rulesets are satisfied.

But it sounds like you want an option to be able to bypass that. Would adding a --pr-merge-bypass-protections be good enough? It would not wait for any rules and just attempt the merge straight away.

However, that's still not the same behavior as pre v1.6.1, where (only) status checks were being enforced. So even if it works for you, it would probably leave someone else broken.

[vbehar]

I agree with you @jashandeep-sohi - by default octopilot should play by the rules. so if the UI says "merging is blocked" then octopilot shouldn't be allowed to merge. That said, we can add a flag to bypass branch protection, which will again have the same behavior as the UI. and we'll see later if it breaks someone else ;-)

[jashandeep-sohi]

I was digging into the API a bit more to see if there's some other way of doing this, and it turns out "branch-protection rules" and "Rulesets" are completely independent from each other. So even pre v1.6.1, I think Rulesets were not being enforced.

Rulesets are a recent addition to the API, so the version of go-github vendored doesn't actually support them. And the GraphQL API support is missing some key features. Like the ability to return what Rulesets apply to a particular branch. Without this you can't determine what checks are required for a PR. So if we want to wait for status checks specified in Rulesets, either we have to move to the latest REST API client or wait until Github adds these features to the GraphQL API.

The GraphQL API does expose a viewerCanMergeAsAdmin on Pull Request, so that might come in handy for the bypass branch protection flag.

[vbehar]

ok thanks. moving to the latest version of the github client sounds like a good idea, so if it works we can do that