Misleading logs when blocked by IP allow list, does not show failure when requesting access token

StephanHCB commented 3 months ago

Checks

[X] I've already read https://docs.github.com/en/actions/hosting-your-own-runners/managing-self-hosted-runners-with-actions-runner-controller/troubleshooting-actions-runner-controller-errors and I'm sure my issue is not covered in the troubleshooting guide.
[X] I am using charts that are officially provided

Controller Version

0.9.2

Deployment Method

ArgoCD

Checks

[X] This isn't a question or user support case (For Q&A and community support, go to Discussions).
[X] I've read the Changelog before submitting this issue and I'm sure it's not due to any recently-introduced backward-incompatible changes

To Reproduce

This problem happened with our Enterprise which has Enterprise Managed Users. Judging from the code, I would expect the same error to occur without EMU, but cannot test this.

1. Configure IP allow list so that it blocks ARC on the enterprise
2. Restart the controller
3. Observe the log

Describe the bug

The logs indicate that obtaining an access token worked when in truth this fails with HTTP 403 due to the missing IP allow list entry.

2024-05-27T09:32:03Z    INFO    actions-clients getting access token for GitHub App auth    {"accessTokenURL": "https://api.github.com/app/installations/<id>/access_tokens"}

GitHub Enterprise support has confirmed that this request actually failed with 403 due to the wrong IP allow list, but there is no log line indicating the error.

The next request then fails with 401, and this is the first error visible in the logs, when in truth this is a consequence of the failure to obtain an access token.

2024-05-27T09:32:03Z    INFO    actions-clients getting runner registration token   {"registrationTokenURL": "https://api.github.com/orgs/<org>/actions/runners/registration-token"}
2024-05-27T09:32:03Z    ERROR   AutoscalingRunnerSet    Failed to get runner group by name  {"version": "0.9.2", "autoscalingrunnerset": {"name":"arc-test-runner","namespace":"cicd"}, "runnerGroup": "operator-runner-group", "error": "failed to get runner registration token on refresh: github api error: StatusCode 401, RequestID \"<omitted>\": {\"message\":\"Bad credentials\",\"documentation_url\":\"https://docs.github.com/rest\"}"}

I believe the error is due to not checking the status code on the HTTP response before parsing the JSON response.

Should insert a status check before this line (and fail and log an error, rather than continue):

https://github.com/actions/actions-runner-controller/blob/master/github/actions/client.go#L1058

Describe the expected behavior

The log should indicate the failure to obtain an access token.

Additional Context

not relevant

Controller Logs

https://gist.github.com/StephanHCB/2028ecfe6ae94cc12a8bd298b1596346

Runner Pod Logs

(no runner pod logs because controller fails to work, so no runners get started)

github-actions[bot] commented 3 months ago

Hello! Thank you for filing an issue.

The maintainers will triage your issue shortly.

In the meantime, please take a look at the troubleshooting guide for bug reports.

If this is a feature request, please review our contribution guidelines.

nikola-jokic commented 3 months ago

Hey @StephanHCB,

Thank you for describing this issue so clearly! We have created a PR that will check the status of the response.

kahirokunn commented 3 months ago

I got the same issue.

actions / actions-runner-controller