Silent push failures on GitHub protected branch

[ellieayla]

The image-automation-controller knew about updated images and was trying to push new commits like this:

kubectl -n flux-system describe ImageUpdateAutomation
...
Status:
  Conditions:
    Last Transition Time:    2021-07-06T19:07:33Z
    Message:                 committed and pushed f4785c946c7f006c85c29eef08a58ac878f7c7c8 to main
    Reason:                  ReconciliationSucceeded
    Status:                  True
    Type:                    Ready
  Last Automation Run Time:  2021-07-06T19:48:15Z
  Last Push Commit:          f4785c946c7f006c85c29eef08a58ac878f7c7c8
  Last Push Time:            2021-07-06T19:48:15Z
  Observed Generation:       1

logged

{"level":"info","ts":"2021-07-06T19:48:21.481Z","logger":"controller-runtime.manager.controller.imageupdateautomation","msg":"pushed commit to origin","reconciler group":"image.toolkit.fluxcd.io","reconciler kind":"ImageUpdateAutomation","name":"tenants","namespace":"flux-system","revision":"f4785c946c7f006c85c29eef08a58ac878f7c7c8","branch":"main"}

That commit f4785c946c7f006c85c29eef08a58ac878f7c7c8 never appeared in the GitHub UI or manual pull or via a GitRepository resource. The GitHub repo had been configured with slightly-more-draconian push restrictions to the main branch. The GitRepository is using gitImplementation: libgit2.

I am presuming that Flux's push attempt would have gotten back something similar to a manual push like...

git push
Enumerating objects: 5, done.
Counting objects: 100% (5/5), done.
Delta compression using up to 12 threads
Compressing objects: 100% (3/3), done.
Writing objects: 100% (3/3), 286 bytes | 286.00 KiB/s, done.
Total 3 (delta 2), reused 0 (delta 0), pack-reused 0
remote: Resolving deltas: 100% (2/2), completed with 2 local objects.
remote: error: GH006: Protected branch update failed for refs/heads/main.
remote: error: At least 1 approving review is required by reviewers with write access.
To github.com:org/repo.git
 ! [remote rejected]   main -> main (protected branch hook declined)
error: failed to push some refs to 'github.com:org/repo.git'

When the branch restrictions were loosened a bit, a subsequent commit+push attempt succeeded.

Status:
  Conditions:
    Last Transition Time:    2021-07-06T19:07:33Z
    Message:                 no updates made; last commit a0fc446 at 2021-07-06T19:52:39Z
    Reason:                  ReconciliationSucceeded
    Status:                  True
    Type:                    Ready
  Last Automation Run Time:  2021-07-06T19:54:51Z
  Last Push Commit:          a0fc4462ce7cd99c212ad4f512ec2ff7ac363fa3
  Last Push Time:            2021-07-06T19:52:39Z
  Observed Generation:       1

logged

{"level":"info","ts":"2021-07-06T19:52:46.033Z","logger":"controller-runtime.manager.controller.imageupdateautomation","msg":"pushed commit to origin","reconciler group":"image.toolkit.fluxcd.io","reconciler kind":"ImageUpdateAutomation","name":"tenants","namespace":"flux-system","revision":"a0fc4462ce7cd99c212ad4f512ec2ff7ac363fa3","branch":"main"}

Commit a0fc4462ce7cd99c212ad4f512ec2ff7ac363fa3 appeared in the GitHub UI & manual pull & via a GitRepository resource.

Concern:

Nothing in the kubectl describe output or controller logs reflected any push failure. I think the only way the above would have been logged is if this push() function didn't produce an err when this happened?

image-automation-controller/controllers/imageupdateautomation_controller.go

Lines 668 to 681 in 5711c59

	func push(ctx context.Context, path, branch string, access repoAccess) error {
	repo, err := libgit2.OpenRepository(path)
	if err != nil {
	return err
	}
	origin, err := repo.Remotes.Lookup(originRemote)
	if err != nil {
	return err
	}
	err = origin.Push([]string{fmt.Sprintf("refs/heads/%s:refs/heads/%s", branch, branch)}, &libgit2.PushOptions{
	RemoteCallbacks: access.remoteCallbacks(),
	})
	return libgit2PushError(err)
	}

[squaremo]

Initial guess: libgit2 doesn't consider rejected refs a failure worthy of an error. The existence of this option suggests that you have to pass a callback to get that info: https://pkg.go.dev/github.com/libgit2/git2go?utm_source=godoc#PushUpdateReferenceCallback (very slightly more detail at https://libgit2.org/libgit2/#HEAD/group/callback/git_push_update_reference_cb).

[squaremo]

I should have said first: excellent bug report, it explains everything I need to start looking for a fix. Thank you @alanjcastonguay!