Actions-runner-controller: Question - How can I create test cases for testing AutoScaler?
Hello,
I configured autoscaler on sandbox environment, and was wondering how can come up with test cases to test the autoscale, scale up and scale down?
Will multiple-jobs suffice to accomplish this test cases?
Thank you,
Laurentius Purba
laurentiuspurba
All 51 comments
@laurentiuspurba Hey!
Will multiple-jobs suffice to accomplish this test cases?
What's exactly multiple-jobs? Do you have any pointer/link for documentation/explanation to it?
Anyway, it depends on which autoscaling strategy/metric you use. For example if you're to use PercentageRunnersBusy you should continue filling up runners by queueing jobs for minutes until the runners get added. Once added, you can stop queueing jobs so that runners get removed gradually.
mumoshu
on 24 Mar 2021
Hello @mumoshu
Sorry, not my intention to introduce new term :-). Multiple jobs is basically defining more than one jobs in github action yaml file.
Regarding metric, I use type: PercentageRunnersBusy. Could you share more information and guide me on what you said about continue filling up runners by queueing jobs for minutes until the runners get added? Do you mind give me pointers on how to accomplish that.
I appreciate your input on this.
Thank you,
Laurentius Purba
laurentiuspurba
on 25 Mar 2021
@mumoshu
I tried with the following jobs, the run-job-number-two kept on running, and I could see the CPU usage was 100% on the POD, but the number of runner pod did not change.
jobs:
run-job-number-one:
runs-on: sandbox-high
steps:
- uses: actions/checkout@v2
- name: Stress test
run: |
dd if=/dev/zero of=/dev/null | dd if=/dev/zero of=/dev/null | dd if=/dev/zero of=/dev/null | dd if=/dev/zero of=/ dev/null
run-job-number-two:
runs-on: sandbox-high
steps:
- uses: actions/checkout@v2
- name: Stress test
run: |
cat /dev/zero > /dev/null
@laurentiuspurba Would you mind sharing your HorizontalRunnerAutoscaler spec in YAML?
mumoshu
on 25 Mar 2021
Hello @mumoshu , below is my HorizontalRunnerAutoscaler.
apiVersion: v1
items:
- apiVersion: actions.summerwind.dev/v1alpha1
kind: HorizontalRunnerAutoscaler
metadata:
name: runner-deployment-autoscaler
namespace: actions-runner-system
spec:
maxReplicas: 5
metrics:
- scaleDownFactor: "0.7"
scaleDownThreshold: "0.3"
scaleUpFactor: "1.4"
scaleUpThreshold: "0.75"
type: PercentageRunnersBusy
minReplicas: 1
scaleDownDelaySecondsAfterScaleOut: 60
scaleTargetRef:
name: runner-deployment
Let me know if you need more info, and/or more tests that I can perform from my end.
Thank you,
Laurentius Purba
laurentiuspurba
on 25 Mar 2021
@laurentiuspurba Thanks! Could you also share logs from actions-runner-controller? It should be writing some messages and hints what it is seeing/trying to do.
mumoshu
on 25 Mar 2021
Hello @mumoshu
I did re-run the job and stop it after running from 7 plus minutes. Not much information that I could gather from controller Pod.
I also attached the CPU usage as for consideration. Let me know if you need more info on this. Appreciate your help.
This is the log when job was running for 7 plus minutes.
...
2021-03-26T13:38:32.345Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-legacy-25c4l", "desired": 1, "available": 1}
2021-03-26T13:38:32.345Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-legacy-25c4l"}
2021-03-26T13:38:32.345Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-tpzj6", "desired": 1, "available": 1}
2021-03-26T13:38:32.345Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-03-26T13:38:32.345Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerdeployment", "request": "actions-runner-system/gannett-org-runner-deployment-legacy"}
2021-03-26T13:38:32.345Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerdeployment", "request": "actions-runner-system/gannett-org-runner-deployment"}
2021-03-26T13:38:49.340Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-legacy-25c4l", "desired": 1, "available": 1}
2021-03-26T13:38:49.340Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-legacy-25c4l"}
2021-03-26T13:38:49.340Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-tpzj6", "desired": 1, "available": 1}
2021-03-26T13:38:49.340Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-03-26T13:38:50.123Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerdeployment", "request": "actions-runner-system/gannett-org-runner-deployment"}
2021-03-26T13:38:50.123Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerdeployment", "request": "actions-runner-system/gannett-org-runner-deployment-legacy"}
2021-03-26T13:38:50.126Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-legacy-25c4l-c2hvl"}
2021-03-26T13:38:50.153Z DEBUG controllers.HorizontalRunnerAutoscaler Calculated desired replicas {"computed_replicas_desired": 1, "spec_replicas_min": 1, "spec_replicas_max": 5, "current_replicas": 1, "num_runners": 2, "num_runners_busy": 1}
2021-03-26T13:38:50.153Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "horizontalrunnerautoscaler", "request": "actions-runner-system/gannett-org-runner-deployment-autoscaler"}
2021-03-26T13:38:50.461Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-hxhdf"}
2021-03-26T13:38:51.450Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-legacy-25c4l-c2hvl"}
2021-03-26T13:38:51.797Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-hxhdf"}
...
...
While this is the log after I cancelled the job.
....
2021-03-26T13:40:04.415Z INFO controllers.Runner Deleted runner pod {"runner": "actions-runner-system/gannett-org-runner-deployment-tpzj6-hxhdf", "repository": ""}
2021-03-26T13:40:04.415Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-hxhdf"}
2021-03-26T13:40:04.415Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-hxhdf"}
2021-03-26T13:40:04.415Z DEBUG controller-runtime.manager.events Normal {"object": {"kind":"Runner","namespace":"actions-runner-system","name":"gannett-org-runner-deployment-tpzj6-hxhdf","uid":"d54615b8-0f69-480c-8dfa-57874348ee6a","apiVersion":"actions.summerwind.dev/v1alpha1","resourceVersion":"325262577"}, "reason": "PodDeleted", "message": "Deleted pod 'gannett-org-runner-deployment-tpzj6-hxhdf'"}
2021-03-26T13:40:04.443Z INFO controllers.Runner Created runner pod {"runner": "actions-runner-system/gannett-org-runner-deployment-tpzj6-hxhdf", "repository": ""}
2021-03-26T13:40:04.443Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-hxhdf"}
2021-03-26T13:40:04.443Z DEBUG controller-runtime.manager.events Normal {"object": {"kind":"Runner","namespace":"actions-runner-system","name":"gannett-org-runner-deployment-tpzj6-hxhdf","uid":"d54615b8-0f69-480c-8dfa-57874348ee6a","apiVersion":"actions.summerwind.dev/v1alpha1","resourceVersion":"325262577"}, "reason": "PodCreated", "message": "Created pod 'gannett-org-runner-deployment-tpzj6-hxhdf'"}
2021-03-26T13:40:04.458Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-tpzj6", "desired": 1, "available": 1}
2021-03-26T13:40:04.460Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-hxhdf"}
2021-03-26T13:40:04.476Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-03-26T13:40:04.477Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-tpzj6", "desired": 1, "available": 1}
2021-03-26T13:40:04.477Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-03-26T13:40:04.477Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerdeployment", "request": "actions-runner-system/gannett-org-runner-deployment"}
2021-03-26T13:40:04.799Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-hxhdf"}
2021-03-26T13:40:05.109Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-hxhdf"}
2021-03-26T13:40:06.282Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-tpzj6", "desired": 1, "available": 1}
2021-03-26T13:40:06.283Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-hxhdf"}
2021-03-26T13:40:06.293Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-03-26T13:40:06.293Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-tpzj6", "desired": 1, "available": 1}
2021-03-26T13:40:06.293Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-03-26T13:40:06.294Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerdeployment", "request": "actions-runner-system/gannett-org-runner-deployment"}
2021-03-26T13:40:06.630Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-hxhdf"}
...
laurentiuspurba
on 26 Mar 2021
Hello @mumoshu
Any updates on this? If you want me to do more tests, just let me know.
Thank you,
laurentiuspurba
on 29 Mar 2021
@laurentiuspurba Hey! Sorry for the delayed response. Perhaps you missed matching controller's sync period and your test case?
The controller poll's GitHub API for scaling runners for each sync period, which is (I thought) set to 15 minutes by default. It should take at least 15 minutes by default to let the controller react on busy runners (by adding pods).
The below is the relevant part of our documentation:
I generally recommend decreasing the sync period to e.g. 1 minute (you'd write it like 1m in your helm values yaml and kustomize patch file) so that you can test it quickly.
mumoshu
on 29 Mar 2021
Hello @mumoshu ,
I just did a quick test by changing the value to 1 on - --sync-period=1m, but still, I did not see my runner-deployment POD being scaled up.
Every 2.0s: kubectl -n actions-runner-system get pods Mon Mar 29 17:23:02 2021
NAME READY STATUS RESTARTS AGE
controller-manager-546b645ff9-bs9nd 2/2 Running 0 15m
gannett-org-runner-deployment-legacy-25c4l-c2hvl 2/2 Running 0 3d3h
gannett-org-runner-deployment-tpzj6-hxhdf 1/1 Running 0 10m
I can see the load was high;
I don't see information on logs telling me about scaling up.
2021-03-29T21:20:51.127Z DEBUG controllers.HorizontalRunnerAutoscaler Calculated desired replicas {"computed_replicas_desired": 1, "spec_replicas_min": 1, "spec_replicas_max": 5, "current_replicas": 1, "num_runners": 2, "num_runners_busy": 1}
2021-03-29T21:20:51.127Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "horizontalrunnerautoscaler", "request": "actions-runner-system/gannett-org-runner-deployment-autoscaler"}
2021-03-29T21:20:51.219Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-hxhdf"}
2021-03-29T21:20:51.552Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-legacy-25c4l-c2hvl"}
2021-03-29T21:20:52.117Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-legacy-25c4l-c2hvl"}
2021-03-29T21:20:52.449Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-hxhdf"}
Anything else that I should look into?
I really appreciate your help on this.
laurentiuspurba
on 29 Mar 2021
@laurentiuspurba Hey! Thanks for the reply.
"num_runners": 2, "num_runners_busy": 1
This part of the log seems to say that you have two runners but only one of them is busy. Then, the controller should have thought the current load is 0.5 compared to scaleUpThreshold: "0.75" (from your HorizontalRunnerAutoscaler spec), which result in NOT scaling out.
Could you either reduce the scaleUpThreshold, or run more GitHub Actions jobs concurrently to scale?
mumoshu
on 29 Mar 2021
@laurentiuspurba Hey! How did your test go? I think you just need to run more jobs concurrently or lower the threshold to trigger the autoscaling behaviour.
mumoshu
on 2 Apr 2021
@mumoshu Hey. I will continue the test Today. I was working on something else yesterday. I will keep you posted.
laurentiuspurba
on 2 Apr 2021
@mumoshu - ~I have 3 jobs that should run parallel, but for some reason, they did not run in parallel. I don't use needs: attribute on these jobs. Any idea?~
I did decrease this value to scaleUpThreshod: "0.5", and it started the scaleup by creating 2 additional Pods.
Every 2.0s: kubectl -n actions-runner-system get pods Mon Apr 5 13:36:01 2021
NAME READY STATUS RESTARTS AGE
controller-manager-5b674b856c-lv4t4 2/2 Running 0 2d23h
gannett-org-runner-deployment-legacy-25c4l-c2hvl 2/2 Running 0 10d
gannett-org-runner-deployment-tpzj6-dvrsl 1/1 Running 0 7s
gannett-org-runner-deployment-tpzj6-hfrzm 1/1 Running 0 2m37s
gannett-org-runner-deployment-tpzj6-hxhdf 1/1 Running 0 9s
Since these jobs were created to spike the CPU usage and will not be stop, so I cancelled those jobs. After waiting for a while, those additional Pods were neve scaled down.
Any idea?
laurentiuspurba
on 5 Apr 2021
After waiting for a while, those additional Pods were neve scaled down.
How long did you wait? Generally speaking you need to wait at least 60 seconds before scale down to happen as you have scaleDownDelaySecondsAfterScaleOut: 60.
Also, would you mind sharing me logs from actions-runner-controller since it started adding runners for scale out, plus the exact date and time you stopped the jobs?
mumoshu
on 5 Apr 2021
@laurentiuspurba Forgot to mention you!
mumoshu
on 5 Apr 2021
@mumoshu This is the log. If you see at the end, you can see the run-job-number-two was canceled.
â–¶ kubectl -n actions-runner-system logs -f gannett-org-runner-deployment-tpzj6-hxhdf
[Mon Apr 5 17:31:29 UTC 2021] [INFO] [/usr/local/bin/startup.sh] Starting supervisor
[Mon Apr 5 17:31:29 UTC 2021] [INFO] [/usr/local/bin/startup.sh] Waiting for processes to be running
[Mon Apr 5 17:31:29 UTC 2021] [INFO] [/usr/local/bin/startup.sh] Process dockerd is not running yet. Retrying in 1 seconds
[Mon Apr 5 17:31:29 UTC 2021] [INFO] [/usr/local/bin/startup.sh] Waited 0 seconds of 30 seconds
[Mon Apr 5 17:31:30 UTC 2021] [INFO] [/usr/local/bin/startup.sh] Process dockerd is not running yet. Retrying in 1 seconds
[Mon Apr 5 17:31:30 UTC 2021] [INFO] [/usr/local/bin/startup.sh] Waited 1 seconds of 30 seconds
[Mon Apr 5 17:31:31 UTC 2021] [INFO] [/usr/local/bin/startup.sh] dockerd is running
Github endpoint URL https://github.com/
--------------------------------------------------------------------------------
| ____ _ _ _ _ _ _ _ _ |
| / ___(_) |_| | | |_ _| |__ / \ ___| |_(_) ___ _ __ ___ |
| | | _| | __| |_| | | | | '_ \ / _ \ / __| __| |/ _ \| '_ \/ __| |
| | |_| | | |_| _ | |_| | |_) | / ___ \ (__| |_| | (_) | | | \__ \ |
| \____|_|\__|_| |_|\__,_|_.__/ /_/ \_\___|\__|_|\___/|_| |_|___/ |
| |
| Self-hosted runner registration |
| |
--------------------------------------------------------------------------------
# Authentication
√ Connected to GitHub
# Runner Registration
A runner exists with the same name
√ Successfully replaced the runner
√ Runner connection is good
# Runner settings
√ Settings Saved.
mkdir: cannot create directory './externals': File exists
mv: cannot stat './externalstmp/*': No such file or directory
16c16
< ./externals/node12/bin/node ./bin/RunnerService.js &
---
> ./externals/node12/bin/node ./bin/RunnerService.js $* &
20c20
< wait $PID
---
> wait $PID
\ No newline at end of file
19c19
< var runService = function () {
---
> var runService = function() {
23c23
< if (!stopping) {
---
> if(!stopping) {
27c27
< listener = childProcess.spawn(listenerExePath, ['run'], { env: process.env });
---
> listener = childProcess.spawn(listenerExePath, ['run'].concat(process.argv.slice(3)), { env: process.env });
30c30
< listener = childProcess.spawn(listenerExePath, ['run', '--startuptype', 'service'], { env: process.env });
---
> listener = childProcess.spawn(listenerExePath, ['run', '--startuptype', 'service'].concat(process.argv.slice(2)), { env: process.env });
33c33
< console.log(`Started listener process, pid: ${listener.pid}`);
---
> console.log('Started listener process');
43,46d42
< listener.on("error", (err) => {
< console.log(`Runner listener fail to start with error ${err.message}`);
< });
<
64c60
< if (!stopping) {
---
> if(!stopping) {
69c65
< } catch (ex) {
---
> } catch(ex) {
78c74
< var gracefulShutdown = function (code) {
---
> var gracefulShutdown = function(code) {
95c91
< });
---
> });
\ No newline at end of file
.path=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
Starting Runner listener with startup type: service
Started listener process
Started running service
√ Connected to GitHub
2021-04-05 17:31:41Z: Listening for Jobs
2021-04-05 17:31:45Z: Running job: run-job-number-two
2021-04-05 17:35:50Z: Job run-job-number-two completed with result: Canceled
Runner listener exited with error code 0
Runner listener exit with 0 return code, stop the service, no retry needed.
@laurentiuspurba Hey! That seems to be logs of your runner pod, not the controller. Would you mind sharing me logs from the controller as you did in https://github.com/summerwind/actions-runner-controller/issues/418#issuecomment-809724417?
It's the controller who watches your K8s resources and GitHub Actions usage so that it can create/delete those runner pods depending on the situation.
mumoshu
on 5 Apr 2021
@mumoshu - ~I re-ran the job, but was not able to trigger scaling up, since I have 2 Pods available. How can I remove one of these Pods, so I can continue testing the scale up and get the logs from controller?~
Nevermind, it is on runnerdeployments.actions.summerwind.dev.
laurentiuspurba
on 6 Apr 2021
@mumoshu This is what I got
- Ran the jobs, and pods were scaled up
controller log after scaling up (click me!!!)
2021-04-06T14:53:05.836Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-04-06T14:53:05.836Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-5f7b8"}
2021-04-06T14:53:05.853Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-2srpp"}
2021-04-06T14:53:05.855Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-tpzj6", "desired": 5, "available": 5}
2021-04-06T14:53:05.855Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-04-06T14:53:05.878Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-mcwcb"}
2021-04-06T14:53:05.878Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-tpzj6", "desired": 5, "available": 5}
2021-04-06T14:53:05.878Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-04-06T14:53:05.893Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-tpzj6", "desired": 5, "available": 5}
2021-04-06T14:53:05.893Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-04-06T14:53:05.895Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-cs44s"}
2021-04-06T14:53:06.284Z ERROR controllers.Runner Failed to check if runner is busy {"runner": "actions-runner-system/gannett-org-runner-deployment-tpzj6-5f7b8", "error": "runner not found"}
github.com/go-logr/zapr.(*zapLogger).Error
/go/pkg/mod/github.com/go-logr/[email protected]/zapr.go:128
github.com/summerwind/actions-runner-controller/controllers.(*RunnerReconciler).Reconcile
/workspace/controllers/runner_controller.go:199
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:256
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:232
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).worker
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:211
k8s.io/apimachinery/pkg/util/wait.JitterUntil.func1
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:152
k8s.io/apimachinery/pkg/util/wait.JitterUntil
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:153
k8s.io/apimachinery/pkg/util/wait.Until
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:88
2021-04-06T14:53:06.284Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-5f7b8"}
2021-04-06T14:53:06.620Z ERROR controllers.Runner Failed to check if runner is busy {"runner": "actions-runner-system/gannett-org-runner-deployment-tpzj6-2srpp", "error": "runner not found"}
github.com/go-logr/zapr.(*zapLogger).Error
/go/pkg/mod/github.com/go-logr/[email protected]/zapr.go:128
github.com/summerwind/actions-runner-controller/controllers.(*RunnerReconciler).Reconcile
/workspace/controllers/runner_controller.go:199
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:256
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:232
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).worker
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:211
k8s.io/apimachinery/pkg/util/wait.JitterUntil.func1
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:152
k8s.io/apimachinery/pkg/util/wait.JitterUntil
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:153
k8s.io/apimachinery/pkg/util/wait.Until
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:88
2021-04-06T14:53:06.620Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-2srpp"}
2021-04-06T14:53:07.014Z ERROR controllers.Runner Failed to check if runner is busy {"runner": "actions-runner-system/gannett-org-runner-deployment-tpzj6-mcwcb", "error": "runner not found"}
github.com/go-logr/zapr.(*zapLogger).Error
/go/pkg/mod/github.com/go-logr/[email protected]/zapr.go:128
github.com/summerwind/actions-runner-controller/controllers.(*RunnerReconciler).Reconcile
/workspace/controllers/runner_controller.go:199
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:256
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:232
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).worker
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:211
k8s.io/apimachinery/pkg/util/wait.JitterUntil.func1
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:152
k8s.io/apimachinery/pkg/util/wait.JitterUntil
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:153
k8s.io/apimachinery/pkg/util/wait.Until
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:88
2021-04-06T14:53:07.014Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-mcwcb"}
2021-04-06T14:53:07.489Z ERROR controllers.Runner Failed to check if runner is busy {"runner": "actions-runner-system/gannett-org-runner-deployment-tpzj6-cs44s", "error": "runner not found"}
github.com/go-logr/zapr.(*zapLogger).Error
/go/pkg/mod/github.com/go-logr/[email protected]/zapr.go:128
github.com/summerwind/actions-runner-controller/controllers.(*RunnerReconciler).Reconcile
/workspace/controllers/runner_controller.go:199
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:256
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:232
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).worker
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:211
k8s.io/apimachinery/pkg/util/wait.JitterUntil.func1
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:152
k8s.io/apimachinery/pkg/util/wait.JitterUntil
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:153
k8s.io/apimachinery/pkg/util/wait.Until
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:88
2021-04-06T14:53:07.489Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-cs44s"}
2021-04-06T14:53:08.124Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-tpzj6", "desired": 5, "available": 5}
2021-04-06T14:53:08.125Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-2srpp"}
2021-04-06T14:53:08.139Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerdeployment", "request": "actions-runner-system/gannett-org-runner-deployment"}
2021-04-06T14:53:08.140Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-04-06T14:53:08.140Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-tpzj6", "desired": 5, "available": 5}
2021-04-06T14:53:08.140Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-04-06T14:53:08.531Z ERROR controllers.Runner Failed to check if runner is busy {"runner": "actions-runner-system/gannett-org-runner-deployment-tpzj6-2srpp", "error": "runner not found"}
github.com/go-logr/zapr.(*zapLogger).Error
/go/pkg/mod/github.com/go-logr/[email protected]/zapr.go:128
github.com/summerwind/actions-runner-controller/controllers.(*RunnerReconciler).Reconcile
/workspace/controllers/runner_controller.go:199
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:256
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:232
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).worker
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:211
k8s.io/apimachinery/pkg/util/wait.JitterUntil.func1
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:152
k8s.io/apimachinery/pkg/util/wait.JitterUntil
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:153
k8s.io/apimachinery/pkg/util/wait.Until
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:88
2021-04-06T14:53:08.531Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-2srpp"}
2021-04-06T14:53:09.631Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-tpzj6", "desired": 5, "available": 5}
2021-04-06T14:53:09.631Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-5f7b8"}
2021-04-06T14:53:09.646Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-04-06T14:53:09.649Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-tpzj6", "desired": 5, "available": 5}
2021-04-06T14:53:09.649Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-04-06T14:53:09.649Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerdeployment", "request": "actions-runner-system/gannett-org-runner-deployment"}
2021-04-06T14:53:09.952Z ERROR controllers.Runner Failed to check if runner is busy {"runner": "actions-runner-system/gannett-org-runner-deployment-tpzj6-5f7b8", "error": "runner not found"}
github.com/go-logr/zapr.(*zapLogger).Error
/go/pkg/mod/github.com/go-logr/[email protected]/zapr.go:128
github.com/summerwind/actions-runner-controller/controllers.(*RunnerReconciler).Reconcile
/workspace/controllers/runner_controller.go:199
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:256
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:232
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).worker
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:211
k8s.io/apimachinery/pkg/util/wait.JitterUntil.func1
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:152
k8s.io/apimachinery/pkg/util/wait.JitterUntil
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:153
k8s.io/apimachinery/pkg/util/wait.Until
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:88
2021-04-06T14:53:09.952Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-5f7b8"}
2021-04-06T14:53:31.583Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-tpzj6", "desired": 5, "available": 5}
2021-04-06T14:53:31.584Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-mcwcb"}
2021-04-06T14:53:31.603Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerdeployment", "request": "actions-runner-system/gannett-org-runner-deployment"}
2021-04-06T14:53:31.603Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-04-06T14:53:31.603Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-tpzj6", "desired": 5, "available": 5}
2021-04-06T14:53:31.603Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-04-06T14:53:31.925Z ERROR controllers.Runner Failed to check if runner is busy {"runner": "actions-runner-system/gannett-org-runner-deployment-tpzj6-mcwcb", "error": "runner not found"}
github.com/go-logr/zapr.(*zapLogger).Error
/go/pkg/mod/github.com/go-logr/[email protected]/zapr.go:128
github.com/summerwind/actions-runner-controller/controllers.(*RunnerReconciler).Reconcile
/workspace/controllers/runner_controller.go:199
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:256
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:232
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).worker
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:211
k8s.io/apimachinery/pkg/util/wait.JitterUntil.func1
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:152
k8s.io/apimachinery/pkg/util/wait.JitterUntil
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:153
k8s.io/apimachinery/pkg/util/wait.Until
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:88
2021-04-06T14:53:31.926Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-mcwcb"}
2021-04-06T14:53:52.803Z ERROR controllers.Runner Failed to check if runner is busy {"runner": "actions-runner-system/gannett-org-runner-deployment-tpzj6-cs44s", "error": "runner not found"}
github.com/go-logr/zapr.(*zapLogger).Error
/go/pkg/mod/github.com/go-logr/[email protected]/zapr.go:128
github.com/summerwind/actions-runner-controller/controllers.(*RunnerReconciler).Reconcile
/workspace/controllers/runner_controller.go:199
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:256
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:232
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).worker
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:211
k8s.io/apimachinery/pkg/util/wait.JitterUntil.func1
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:152
k8s.io/apimachinery/pkg/util/wait.JitterUntil
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:153
k8s.io/apimachinery/pkg/util/wait.Until
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:88
2021-04-06T14:53:52.803Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-cs44s"}
2021-04-06T14:53:54.658Z ERROR controllers.Runner Failed to check if runner is busy {"runner": "actions-runner-system/gannett-org-runner-deployment-tpzj6-cs44s", "error": "runner not found"}
github.com/go-logr/zapr.(*zapLogger).Error
/go/pkg/mod/github.com/go-logr/[email protected]/zapr.go:128
github.com/summerwind/actions-runner-controller/controllers.(*RunnerReconciler).Reconcile
/workspace/controllers/runner_controller.go:199
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:256
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:232
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).worker
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:211
k8s.io/apimachinery/pkg/util/wait.JitterUntil.func1
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:152
k8s.io/apimachinery/pkg/util/wait.JitterUntil
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:153
k8s.io/apimachinery/pkg/util/wait.Until
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:88
2021-04-06T14:53:54.658Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-cs44s"}
2021-04-06T14:54:01.203Z ERROR controllers.Runner Failed to check if runner is busy {"runner": "actions-runner-system/gannett-org-runner-deployment-tpzj6-cs44s", "error": "runner not found"}
github.com/go-logr/zapr.(*zapLogger).Error
/go/pkg/mod/github.com/go-logr/[email protected]/zapr.go:128
github.com/summerwind/actions-runner-controller/controllers.(*RunnerReconciler).Reconcile
/workspace/controllers/runner_controller.go:199
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:256
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:232
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).worker
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:211
k8s.io/apimachinery/pkg/util/wait.JitterUntil.func1
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:152
k8s.io/apimachinery/pkg/util/wait.JitterUntil
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:153
k8s.io/apimachinery/pkg/util/wait.Until
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:88
2021-04-06T14:54:01.203Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-cs44s"}
Every 2.0s: kubectl -n actions-runner-system get pods
NAME READY STATUS RESTARTS AGE
controller-manager-5b674b856c-lv4t4 2/2 Running 0 3d20h
gannett-org-runner-deployment-gerardo-lwvwm-lj4x2 1/1 Running 0 4m11s
gannett-org-runner-deployment-legacy-25c4l-c2hvl 2/2 Running 0 8h
gannett-org-runner-deployment-tpzj6-2srpp 1/1 Running 0 3m28s
gannett-org-runner-deployment-tpzj6-5f7b8 1/1 Running 0 3m28s
gannett-org-runner-deployment-tpzj6-cs44s 1/1 Running 0 3m28s
gannett-org-runner-deployment-tpzj6-dtwcm 1/1 Running 0 33m
gannett-org-runner-deployment-tpzj6-mcwcb 1/1 Running 0 3m28s
Logs after cancelling jobs (click me!!!)
2021-04-06T14:56:36.016Z INFO controllers.Runner Deleted runner pod {"runner": "actions-runner-system/gannett-org-runner-deployment-tpzj6-dtwcm", "repository": ""}
2021-04-06T14:56:36.016Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-dtwcm"}
2021-04-06T14:56:36.016Z DEBUG controller-runtime.manager.events Normal {"object": {"kind":"Runner","namespace":"actions-runner-system","name":"gannett-org-runner-deployment-tpzj6-dtwcm","uid":"ab2dc9f5-8060-4c46-a092-8325e41c8b0a","apiVersion":"actions.summerwind.dev/v1alpha1","resourceVersion":"334679144"}, "reason": "PodDeleted", "message": "Deleted pod 'gannett-org-runner-deployment-tpzj6-dtwcm'"}
2021-04-06T14:56:36.587Z INFO controllers.Runner Deleted runner pod {"runner": "actions-runner-system/gannett-org-runner-deployment-gerardo-lwvwm-lj4x2", "repository": ""}
2021-04-06T14:56:36.587Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-gerardo-lwvwm-lj4x2"}
2021-04-06T14:56:36.587Z DEBUG controller-runtime.manager.events Normal {"object": {"kind":"Runner","namespace":"actions-runner-system","name":"gannett-org-runner-deployment-gerardo-lwvwm-lj4x2","uid":"7a29415b-442b-4713-b3ee-d61d2ed9901d","apiVersion":"actions.summerwind.dev/v1alpha1","resourceVersion":"334690562"}, "reason": "PodDeleted", "message": "Deleted pod 'gannett-org-runner-deployment-gerardo-lwvwm-lj4x2'"}
2021-04-06T14:56:36.647Z INFO controllers.Runner Created runner pod {"runner": "actions-runner-system/gannett-org-runner-deployment-tpzj6-dtwcm", "repository": ""}
2021-04-06T14:56:36.647Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-dtwcm"}
2021-04-06T14:56:36.647Z DEBUG controller-runtime.manager.events Normal {"object": {"kind":"Runner","namespace":"actions-runner-system","name":"gannett-org-runner-deployment-tpzj6-dtwcm","uid":"ab2dc9f5-8060-4c46-a092-8325e41c8b0a","apiVersion":"actions.summerwind.dev/v1alpha1","resourceVersion":"334679144"}, "reason": "PodCreated", "message": "Created pod 'gannett-org-runner-deployment-tpzj6-dtwcm'"}
2021-04-06T14:56:36.682Z INFO controllers.Runner Created runner pod {"runner": "actions-runner-system/gannett-org-runner-deployment-gerardo-lwvwm-lj4x2", "repository": ""}
2021-04-06T14:56:36.682Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-gerardo-lwvwm-lj4x2"}
2021-04-06T14:56:36.682Z DEBUG controller-runtime.manager.events Normal {"object": {"kind":"Runner","namespace":"actions-runner-system","name":"gannett-org-runner-deployment-gerardo-lwvwm-lj4x2","uid":"7a29415b-442b-4713-b3ee-d61d2ed9901d","apiVersion":"actions.summerwind.dev/v1alpha1","resourceVersion":"334690562"}, "reason": "PodCreated", "message": "Created pod 'gannett-org-runner-deployment-gerardo-lwvwm-lj4x2'"}
2021-04-06T14:56:36.704Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-tpzj6", "desired": 5, "available": 5}
2021-04-06T14:56:36.705Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-dtwcm"}
2021-04-06T14:56:36.724Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-04-06T14:56:36.724Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-tpzj6", "desired": 5, "available": 5}
2021-04-06T14:56:36.724Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-04-06T14:56:36.735Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-gerardo-lwvwm-lj4x2"}
2021-04-06T14:56:36.780Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerdeployment", "request": "actions-runner-system/gannett-org-runner-deployment"}
2021-04-06T14:56:36.780Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-gerardo-lwvwm", "desired": 1, "available": 1}
2021-04-06T14:56:36.794Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-gerardo-lwvwm"}
2021-04-06T14:56:36.795Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-gerardo-lwvwm", "desired": 1, "available": 1}
2021-04-06T14:56:36.795Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-gerardo-lwvwm"}
2021-04-06T14:56:36.795Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerdeployment", "request": "actions-runner-system/gannett-org-runner-deployment-gerardo"}
2021-04-06T14:56:37.329Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-dtwcm"}
2021-04-06T14:56:37.925Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-gerardo-lwvwm-lj4x2"}
2021-04-06T14:56:38.534Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-tpzj6", "desired": 5, "available": 5}
2021-04-06T14:56:38.534Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-dtwcm"}
2021-04-06T14:56:38.556Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-04-06T14:56:38.558Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-tpzj6", "desired": 5, "available": 5}
2021-04-06T14:56:38.558Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-04-06T14:56:38.558Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerdeployment", "request": "actions-runner-system/gannett-org-runner-deployment"}
2021-04-06T14:56:39.309Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-dtwcm"}
2021-04-06T14:56:39.325Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-gerardo-lwvwm", "desired": 1, "available": 1}
2021-04-06T14:56:39.325Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-gerardo-lwvwm-lj4x2"}
2021-04-06T14:56:39.344Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-gerardo-lwvwm"}
2021-04-06T14:56:39.344Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerdeployment", "request": "actions-runner-system/gannett-org-runner-deployment-gerardo"}
2021-04-06T14:56:39.344Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-gerardo-lwvwm", "desired": 1, "available": 1}
2021-04-06T14:56:39.344Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-gerardo-lwvwm"}
2021-04-06T14:56:39.822Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-gerardo-lwvwm-lj4x2"}
- Then I wait for more than 3 minutes
Logs after waiting for 3 minutes after cancelling jobs (click me!!!)
2021-04-06T15:03:11.337Z DEBUG controller-runtime.webhook.webhooks wrote response {"webhook": "/validate-actions-summerwind-dev-v1alpha1-runner", "UID": "9ba9b19d-9a81-48ec-b6d0-7202669192f8", "allowed": true, "result": {}, "resultError": "got runtime.Object without object metadata: &Status{ListMeta:ListMeta{SelfLink:,ResourceVersion:,Continue:,RemainingItemCount:nil,},Status:,Message:,Reason:,Details:nil,Code:200,}"}
2021-04-06T15:03:11.352Z DEBUG controller-runtime.webhook.webhooks received request {"webhook": "/mutate-actions-summerwind-dev-v1alpha1-runner", "UID": "51774c0d-c5ec-479b-916d-141de7beb82f", "kind": "actions.summerwind.dev/v1alpha1, Kind=Runner", "resource": {"group":"actions.summerwind.dev","version":"v1alpha1","resource":"runners"}}
2021-04-06T15:03:11.352Z DEBUG controller-runtime.webhook.webhooks wrote response {"webhook": "/mutate-actions-summerwind-dev-v1alpha1-runner", "UID": "51774c0d-c5ec-479b-916d-141de7beb82f", "allowed": true, "result": {}, "resultError": "got runtime.Object without object metadata: &Status{ListMeta:ListMeta{SelfLink:,ResourceVersion:,Continue:,RemainingItemCount:nil,},Status:,Message:,Reason:,Details:nil,Code:200,}"}
2021-04-06T15:03:11.356Z DEBUG controller-runtime.webhook.webhooks received request {"webhook": "/validate-actions-summerwind-dev-v1alpha1-runner", "UID": "68ac06c3-9105-4a67-ac83-7c2076a7eba6", "kind": "actions.summerwind.dev/v1alpha1, Kind=Runner", "resource": {"group":"actions.summerwind.dev","version":"v1alpha1","resource":"runners"}}
2021-04-06T15:03:11.356Z INFO runner-resource validate resource to be updated {"name": "gannett-org-runner-deployment-tpzj6-97rk8"}
2021-04-06T15:03:11.356Z DEBUG controller-runtime.webhook.webhooks wrote response {"webhook": "/validate-actions-summerwind-dev-v1alpha1-runner", "UID": "68ac06c3-9105-4a67-ac83-7c2076a7eba6", "allowed": true, "result": {}, "resultError": "got runtime.Object without object metadata: &Status{ListMeta:ListMeta{SelfLink:,ResourceVersion:,Continue:,RemainingItemCount:nil,},Status:,Message:,Reason:,Details:nil,Code:200,}"}
2021-04-06T15:03:11.365Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerdeployment", "request": "actions-runner-system/gannett-org-runner-deployment"}
2021-04-06T15:03:11.366Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-04-06T15:03:11.366Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-tpzj6", "desired": 4, "available": 4}
2021-04-06T15:03:11.372Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-97rk8"}
2021-04-06T15:03:11.378Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-04-06T15:03:11.378Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerdeployment", "request": "actions-runner-system/gannett-org-runner-deployment"}
2021-04-06T15:03:11.378Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-tpzj6", "desired": 4, "available": 4}
2021-04-06T15:03:11.378Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-04-06T15:03:11.390Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-tpzj6", "desired": 4, "available": 4}
2021-04-06T15:03:11.390Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-04-06T15:03:11.390Z INFO controllers.Runner Updated registration token {"runner": "gannett-org-runner-deployment-tpzj6-97rk8", "repository": ""}
2021-04-06T15:03:11.390Z DEBUG controller-runtime.manager.events Normal {"object": {"kind":"Runner","namespace":"actions-runner-system","name":"gannett-org-runner-deployment-tpzj6-97rk8","uid":"0076d23d-953b-433a-8ace-97a60ed37c77","apiVersion":"actions.summerwind.dev/v1alpha1","resourceVersion":"334697348"}, "reason": "RegistrationTokenUpdated", "message": "Successfully update registration token"}
2021-04-06T15:03:11.416Z INFO controllers.Runner Created runner pod {"runner": "actions-runner-system/gannett-org-runner-deployment-tpzj6-97rk8", "repository": ""}
2021-04-06T15:03:11.416Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-97rk8"}
2021-04-06T15:03:11.416Z DEBUG controller-runtime.manager.events Normal {"object": {"kind":"Runner","namespace":"actions-runner-system","name":"gannett-org-runner-deployment-tpzj6-97rk8","uid":"0076d23d-953b-433a-8ace-97a60ed37c77","apiVersion":"actions.summerwind.dev/v1alpha1","resourceVersion":"334697350"}, "reason": "PodCreated", "message": "Created pod 'gannett-org-runner-deployment-tpzj6-97rk8'"}
2021-04-06T15:03:11.435Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-97rk8"}
2021-04-06T15:03:11.478Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-tpzj6", "desired": 4, "available": 4}
2021-04-06T15:03:11.478Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-04-06T15:03:11.478Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-tpzj6", "desired": 4, "available": 4}
2021-04-06T15:03:11.478Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-04-06T15:03:11.851Z ERROR controllers.Runner Failed to check if runner is busy {"runner": "actions-runner-system/gannett-org-runner-deployment-tpzj6-97rk8", "error": "runner not found"}
github.com/go-logr/zapr.(*zapLogger).Error
/go/pkg/mod/github.com/go-logr/[email protected]/zapr.go:128
github.com/summerwind/actions-runner-controller/controllers.(*RunnerReconciler).Reconcile
/workspace/controllers/runner_controller.go:199
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:256
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:232
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).worker
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:211
k8s.io/apimachinery/pkg/util/wait.JitterUntil.func1
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:152
k8s.io/apimachinery/pkg/util/wait.JitterUntil
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:153
k8s.io/apimachinery/pkg/util/wait.Until
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:88
2021-04-06T15:03:11.851Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-97rk8"}
2021-04-06T15:03:11.851Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-5f7b8"}
2021-04-06T15:03:12.294Z ERROR controllers.Runner Failed to check if runner is busy {"runner": "actions-runner-system/gannett-org-runner-deployment-tpzj6-97rk8", "error": "runner not found"}
github.com/go-logr/zapr.(*zapLogger).Error
/go/pkg/mod/github.com/go-logr/[email protected]/zapr.go:128
github.com/summerwind/actions-runner-controller/controllers.(*RunnerReconciler).Reconcile
/workspace/controllers/runner_controller.go:199
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:256
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:232
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).worker
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:211
k8s.io/apimachinery/pkg/util/wait.JitterUntil.func1
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:152
k8s.io/apimachinery/pkg/util/wait.JitterUntil
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:153
k8s.io/apimachinery/pkg/util/wait.Until
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:88
2021-04-06T15:03:12.294Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-97rk8"}
2021-04-06T15:03:12.659Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-mcwcb"}
2021-04-06T15:03:15.416Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-97rk8"}
2021-04-06T15:03:15.416Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-tpzj6", "desired": 4, "available": 4}
2021-04-06T15:03:15.432Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerdeployment", "request": "actions-runner-system/gannett-org-runner-deployment"}
2021-04-06T15:03:15.432Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-04-06T15:03:15.432Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-tpzj6", "desired": 4, "available": 4}
2021-04-06T15:03:15.432Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-04-06T15:03:15.918Z ERROR controllers.Runner Failed to check if runner is busy {"runner": "actions-runner-system/gannett-org-runner-deployment-tpzj6-97rk8", "error": "runner not found"}
github.com/go-logr/zapr.(*zapLogger).Error
/go/pkg/mod/github.com/go-logr/[email protected]/zapr.go:128
github.com/summerwind/actions-runner-controller/controllers.(*RunnerReconciler).Reconcile
/workspace/controllers/runner_controller.go:199
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:256
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:232
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).worker
/go/pkg/mod/sigs.k8s.io/[email protected]/pkg/internal/controller/controller.go:211
k8s.io/apimachinery/pkg/util/wait.JitterUntil.func1
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:152
k8s.io/apimachinery/pkg/util/wait.JitterUntil
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:153
k8s.io/apimachinery/pkg/util/wait.Until
/go/pkg/mod/k8s.io/[email protected]/pkg/util/wait/wait.go:88
2021-04-06T15:03:15.918Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-97rk8"}
2021-04-06T15:03:15.919Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-mcwcb"}
2021-04-06T15:03:21.735Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-5f7b8"}
2021-04-06T15:03:21.750Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-5f7b8"}
More logs showed controller's HorizontalRunnerAutoscaller (click me!!!)
2021-04-06T15:12:45.600Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-legacy-25c4l", "desired": 1, "available": 1}
2021-04-06T15:12:45.600Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-legacy-25c4l"}
2021-04-06T15:12:45.600Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-tpzj6", "desired": 4, "available": 4}
2021-04-06T15:12:45.600Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-04-06T15:12:45.600Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerdeployment", "request": "actions-runner-system/gannett-org-runner-deployment-legacy"}
2021-04-06T15:12:45.600Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-gerardo-lwvwm", "desired": 1, "available": 1}
2021-04-06T15:12:45.600Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-gerardo-lwvwm"}
2021-04-06T15:12:45.600Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerdeployment", "request": "actions-runner-system/gannett-org-runner-deployment"}
2021-04-06T15:12:45.600Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerdeployment", "request": "actions-runner-system/gannett-org-runner-deployment-gerardo"}
2021-04-06T15:13:02.599Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerdeployment", "request": "actions-runner-system/gannett-org-runner-deployment"}
2021-04-06T15:13:02.599Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-tpzj6", "desired": 4, "available": 4}
2021-04-06T15:13:02.599Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-04-06T15:13:02.599Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerdeployment", "request": "actions-runner-system/gannett-org-runner-deployment-legacy"}
2021-04-06T15:13:02.599Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-gerardo-lwvwm", "desired": 1, "available": 1}
2021-04-06T15:13:02.599Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-gerardo-lwvwm"}
2021-04-06T15:13:02.599Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-legacy-25c4l", "desired": 1, "available": 1}
2021-04-06T15:13:02.599Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-legacy-25c4l"}
2021-04-06T15:13:02.599Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerdeployment", "request": "actions-runner-system/gannett-org-runner-deployment-gerardo"}
2021-04-06T15:13:02.599Z INFO controllers.RunnerReplicaSet debug {"runnerreplicaset": "actions-runner-system/gannett-org-runner-deployment-tpzj6", "desired": 4, "available": 4}
2021-04-06T15:13:02.599Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runnerreplicaset", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6"}
2021-04-06T15:13:03.076Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-2srpp"}
2021-04-06T15:13:03.077Z DEBUG controllers.HorizontalRunnerAutoscaler Calculated desired replicas {"computed_replicas_desired": 4, "spec_replicas_min": 1, "spec_replicas_max": 5, "current_replicas": 4, "num_runners": 6, "num_runners_busy": 0}
2021-04-06T15:13:03.096Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "horizontalrunnerautoscaler", "request": "actions-runner-system/gannett-org-runner-deployment-autoscaler"}
2021-04-06T15:13:03.643Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-cs44s"}
2021-04-06T15:13:03.716Z DEBUG controllers.HorizontalRunnerAutoscaler Calculated desired replicas {"computed_replicas_desired": 4, "spec_replicas_min": 1, "spec_replicas_max": 5, "current_replicas": 4, "num_runners": 6, "num_runners_busy": 0}
2021-04-06T15:13:03.716Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "horizontalrunnerautoscaler", "request": "actions-runner-system/gannett-org-runner-deployment-autoscaler"}
2021-04-06T15:13:04.120Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-gerardo-lwvwm-lj4x2"}
2021-04-06T15:13:04.592Z DEBUG controller-runtime.controller Successfully Reconciled {"controller": "runner", "request": "actions-runner-system/gannett-org-runner-deployment-tpzj6-dtwcm"}
Checking number of Pods -> It became 4.
Every 2.0s: kubectl -n actions-runner-system get pods
NAME READY STATUS RESTARTS AGE
controller-manager-5b674b856c-lv4t4 2/2 Running 0 3d20h
gannett-org-runner-deployment-gerardo-lwvwm-lj4x2 1/1 Running 0 63s
gannett-org-runner-deployment-legacy-25c4l-c2hvl 2/2 Running 0 8h
gannett-org-runner-deployment-tpzj6-2srpp 1/1 Running 0 11m
gannett-org-runner-deployment-tpzj6-97rk8 1/1 Running 0 60s
gannett-org-runner-deployment-tpzj6-cs44s 1/1 Running 0 11m
gannett-org-runner-deployment-tpzj6-dtwcm 1/1 Running 0 7m35s
Hope that helps.
laurentiuspurba
on 6 Apr 2021
@laurentiuspurba Thank you so much for the response!
Unforutnately all I can see for now is that your controller is somehow thinking the calculated desired replicas should be 4 even though the number of busy runners is 0.
2021-04-06T15:13:03.716Z DEBUG controllers.HorizontalRunnerAutoscaler Calculated desired replicas {"computed_replicas_desired": 4, "spec_replicas_min": 1, "spec_replicas_max": 5, "current_replicas": 4, "num_runners": 6, "num_runners_busy": 0}
I'm not entirely sure but could this be a bug?
Out of curiosity, which version of actions-runner-controller are you using? I think I've never encountered this myself but I think it worth trying to replicate your setup as much as possible and try to reproduce your issue myself.
Also, could you try updating the controller to the latest version of actions-runner-controller, v0.18.2? That version improved logging so you'll probably get much more information for debugging. It also improved reliability so the autoscaler should react more quickly and reliably.
Sorry for the back and forth but I'll keep doing my best supporting you. Thanks!
mumoshu
on 7 Apr 2021
@mumoshu - Currently we are using v0.17.0. And yesterday, I tried to upgrade ours to v0.18.2, as follows:
- I copied CRDs file from https://github.com/summerwind/actions-runner-controller/releases/download/v0.18.2/actions-runner-controller.yaml
- Update the
scaleUpThresholdto be "0.50" - Added/Enabled
autoscalerEnabled: trueon values. yaml
After the above changes, I applied those changes, and got the following:
- The 2 types of runners,
gannett-org-runner-deploymentandgannett-org-runner-deployment-legacywere spawning out of control.
We did not event start the job yet, but for some reasons those runner Pods spawned up to 200 Pods, that causing lots of issues on our systems.
This caused Github API rate limit issue, so we had to delete:
- All runner Pods.
- horizontalrunnerautoscalers.actions.summerwind.dev
One other thing, after deleting all the pods using kubectl delete pods ... command, I still can see Runner were still there by issuing this command
kubectl -n actions-runner-system get runners.
Is deleting the pods does not automatically deletes the Runner?
Let me know if you have a docs on best practice to upgrade.
Thank you.
laurentiuspurba
on 7 Apr 2021
One other thing, after deleting all the pods using kubectl delete pods ... command, I still can see Runner were still there by issuing this command
kubectl -n actions-runner-system get runners.
This occurs when doing uninstalls of the runners with Helm, we wrapper our runners in a Helm chart as we are a Helm shop. To delete the runners after the underlying pods are gone you will need to POST directly to the k8s API to tell it to drop the finaliser for the runners:
Roughly this:
kubectl get runner %RUNNER_NAME% -o json > runner.json- Find your finalisers in your JSON and remove the entries, they should end up looking something like this:
"finalizers": [
],
- Post your JSON directly to the k8s API
kubectl replace --raw "/apis/actions.summerwind.dev/v1alpha1/namespaces/%YOUR_ACTIONS_NAMESPACE%/runners/%RUNNER_NAME%" -f ./runner.json
I think in general you should be deleting the runner kind rather than the underlying pod. Deleting the runner kind should delete the underlying pod, I'm not super sure what is the expected behaviour when you delete the pod instead but I don't think it would delete a custom resource.
The pod doesn't have a finaliser associated (kubectl get pod %RUNNER_POD_NAME% -o json > pod.json) so I don't think it would know to delete the runner, conversely the runner has the CRD as a finaliser so it would know that there is a underlying pod backing the runner and would delete it.
callum-tait-pbx
on 7 Apr 2021
@laurentiuspurba One thing to add- It seems like you ended up with a situation same as #427. The inifite scale can be due to outdated Runner CRD(not Runner resources) so you need to upgrade it to that of v0.18.
Also note that Helm 3, as far as I know, doesn't apply CRDs on helm-upgrade. So you'll need to do it manually.
mumoshu
on 7 Apr 2021
@callum-tait-pbx - I was able to delete the runners using your step-by-step instruction, and it went down from +/- 2000 to 501, and it stopped at 501.
So, I tried your instruction again and got the following
â–¶ kubectl replace --raw "/apis/actions.summerwind.dev/v1alpha1/namespaces/actions-runner-system/runners/gannett-org-runner-deployment-legacy-25c4l-s2s2c" -f runner1.json
The Runner "gannett-org-runner-deployment-legacy-25c4l-s2s2c" is invalid:
* status.message: Required value
* status.phase: Required value
* status.reason: Required value
I did a quick check on this runner and compare it with running runner.
Non-status runner
â–¶ kubectl -n actions-runner-system get runners gannett-org-runner-deployment-legacy-25c4l-s2s2c -o json | grep -A 30 status
"status": {
"message": "",
"phase": "Running",
"reason": "",
"registration": {
"expiresAt": "2021-04-07T20:58:03Z",
"labels": [
"cloud-engineering",
"sandbox-high"
],
"organization": "hidden",
"token": "HIDDEN"
}
}
}
runner with Running status
â–¶ kubectl -n actions-runner-system get runners gannett-org-runner-deployment-legacy-25c4l-2242n -o json | grep -A 30 status
"status": {
"registration": {
"expiresAt": "2021-04-06T18:57:48Z",
"labels": [
"cloud-engineering",
"sandbox-high-legacy"
],
"organization": "hidden",
"token": "HIDDEN"
}
}
}
kubectl delete --force does not help either.
Any idea?
laurentiuspurba
on 7 Apr 2021
@laurentiuspurba Argh, I have never encountered and handled such case myself, but I can imagine how that can happen.
You seem to have mixed runners before/after the controller update now. Either try starting the controller (if you didn't yet), or just set empty strings to those required status fields by using .e.g. kubectl edit, or just include the below to your runner1.json used for replace. Beware not to have multiple status. Instead, add fields like message to the existing status field.
status:
message: ""
phase: ""
reason: ""
This way the validation error will go away and you'll finally be able to delete/remove the finalizer.
mumoshu
on 7 Apr 2021
Beat me to it @mumoshu :D I was about to post that!
Also note that Helm 3, as far as I know, doesn't apply CRDs on helm-upgrade. So you'll need to do it manually.
Yeh, Helm doesn't support upgrading or deleting CRDs by design https://helm.sh/docs/chart_best_practices/custom_resource_definitions/. I previously thought that was strictly the CRD definition itself but I think it also includes the custom objects themselves annoyingly. It just makes doing upgrades and clean up have an annoying manual step so it's not the end of the world. I don't think there is a way around it really.
callum-tait-pbx
on 7 Apr 2021
@callum-tait-pbx and @mumoshu Thanks for your replies.
I tried those 2 options:
- Added
message: "",phase: "",reason: ""torunner1.jsonand re-ran thekubectl replace ... kubectl edit runner ..and added those fields
but the result is the same, No good.
The kubectl edit... prompted me to save to a file, which I did, and then did kubectl apply -f..., but got the same error.
Right now, I had to delete the controller, since for some reason the controller was still pinging github that caused my github rate limit used up.
Any suggestions are appreciated.
Thank you.
laurentiuspurba
on 7 Apr 2021
I'm not super sure how the runners have got in this state, those properties have been in the runner CRD for a long time so I'm not sure how an upgrade could break things in this way but it does seem to be the smoking gun.
I don't think you'll be able to go via the cli kubectl at this point because of the mismatch between validation and object. I think you'll need to post directly to the API as before. You should be able to bolt on those fields onto your status document in addition to whatever else is there:
{
"apiVersion": "actions.summerwind.dev/v1alpha1",
"kind": "Runner",
"metadata": { ...
},
"spec": { ...
},
"status": {
"message": "",
"phase": "",
"reason": "",
}
@laurentiuspurba Could you also try reverting your Runner CRD to that of v0.17.x you used before? That would be another way to "fix" the validation error, without figuring out how to manually add status fields like message to fix it.
mumoshu
on 7 Apr 2021
@mumoshu - Sorry forgot to mention that. After Pods were spawning out of control, I did revert back to CRD v0.17.0. So right now, I have v0.17.0 in my system.
laurentiuspurba
on 7 Apr 2021
@laurentiuspurba Thanks for clarifying! Okay then you should not encounter the following validation error anymore, right?
* status.message: Required value
* status.phase: Required value
* status.reason: Required value
@laurentiuspurba BTW, the important point for me was that you sometimes need to kubectl delete and then kubectl create to recreate the CRD, rather than kubectl applying the CRD, for the change to take effect. To verify the content of CRD is exactly as what you expect, please run kubectl get -o yaml $RUNNER_CRD_NAME
mumoshu
on 8 Apr 2021
@mumoshu - That's actualy the issue that I'm having right now with the following fields and values
* status.message: Required value
* status.phase: Required value
* status.reason: Required value
````
It was stuck while issuing `kubectl get -o yaml $RUNNER_CRD_NAME` command. I don't know if I have to wait for minutes. I'm getting confused :-(
Had to cancel that commands.
â–¶ kubectl -n actions-runner-system get crd runnerdeployments.actions.summerwind.dev -o yaml
apiVersion: apiextensions.k8s.io/v1
kind: CustomResourceDefinition
metadata:
annotations:
controller-gen.kubebuilder.io/version: v0.3.0
kubectl.kubernetes.io/last-applied-configuration: |
ç^C
â–¶ kubectl -n actions-runner-system get crd runners.actions.summerwind.dev -o yaml
apiVersion: apiextensions.k8s.io/v1
kind: CustomResourceDefinition
metadata:
annotations:
controller-gen.kubebuilder.io/version: v0.3.0
kubectl.kubernetes.io/last-applied-configuration: |
^C
```
laurentiuspurba
on 8 Apr 2021
@laurentiuspurba Sorry I've been pretty confused in the last two comments I've already removed 😓
Well, so the validation error seems to happen with v0.17 version of the CRD. So you need to upgrade it to v0.18 version. I believe the validation error you originally reported at https://github.com/summerwind/actions-runner-controller/issues/418#issuecomment-815238074 happened due to you reverted the CRD to the v0.17 version.
So, could you recreate the CRD to the v0.18 version, and try deleting/patching/etc runners?
mumoshu
on 8 Apr 2021
@mumoshu The concern if I'm going to update to v0.18.0 is the pods and/or runners will be spawned out of control and it will affect our Github rate limit. That's what happened when I did the upgrade from v0.17.0 to v0.18.2, and my other teams started to noticed that they were not able to use Github Actions due to the rate limit.
Is there a better way to prevent this, especially in regards to exhausted Github rate limit?
laurentiuspurba
on 8 Apr 2021
@laurentiuspurba A few points first:
- I'd recommend v0.18.2 than v0.18.0 as it contains a few useful fixes
- It shouldn't happen as long as you recreate the runner CRD before upgrading the controller
- One of our users has just reported that scale-down didn't work in pre v0.18 started working in v0.18.2(or probably 0.18) https://github.com/summerwind/actions-runner-controller/issues/248#issuecomment-815368305
my other teams started to noticed that they were not able to use Github Actions due to the rate limit.
I'm not sure how this can happen in real-life. Could you elaborate on your setup a bit more?
Are you sharing the github token/github app that you provided to actions-runner-controller with anything else? If so, I'd suggest creating a dedicated token or github app for actions-runner-controller to isolate rate limit to a single token/app.
mumoshu
on 8 Apr 2021
Also... I'd like to fix that "infinite scale" to not occur when the CRD isn't good, so that, in the future versions, it's a matter of just updating the container image tag to the older one when you need rolling-back.
It's absolutely a nightmare when you're forced to run a lot of investigations/manual intervations to just roll it back to the previous state(sorry about that!)
mumoshu
on 8 Apr 2021
@mumoshu Thanks for your suggestions. Let me create a dedicated token or github app for actions-runner-controller to prevent rate limit issue. I will keep you posted.
laurentiuspurba
on 8 Apr 2021
@laurentiuspurba Thanks! FYI, our documentation for setting up a token/app would be helpful.
mumoshu
on 8 Apr 2021
@laurentiuspurba there isn't really any reason not to set the project with a github app tbh.
I've adopted just nuking all of my runner kinds as a first step when doing an upgrade as the CRDs complicate things a lot. In theory if your upgrade doesn't involve any CRD changes you should be able to just bump the manager app version and be on your merry way. So far however the CRDs haven't been very static and so most upgrades involve new CRD changes.
callum-tait-pbx
on 8 Apr 2021
// BTW, I was wondering if kubectl-replace rather than kubectl-apply would help upgrading CRD without hassle and nuking the whole thing.
mumoshu
on 8 Apr 2021
Potentially, replace is imperative where as apply is declarative so it changes the underlying logic at play considerably, this potentially may help for those deplying via kubectl, fairly easy to test for anyone in that setup who is interested, we use Helmsman where I work so there isn't much we can do. I was consdering creating a PR to allow you to deploy the chart without the CRDs, copying cert-manager basically. It's quite a common practice to wrap your CRDs is a seperate chart as they are such a pain in the arse to work with with Helm.
https://helm.sh/docs/chart_best_practices/custom_resource_definitions/ see method 2
callum-tait-pbx
on 8 Apr 2021
Hello @mumoshu and @callum-tait-pbx
I finally nuked existing installation (_just got back from days off_), and then re-generated the manifest file and re-applied that file that was configured with new testing Github token.
Currently, version 0.17.0 is up and running, and I would likt to upgrade to v0.18.2.
Do you mind reviewing the following steps to upgrade to v0.18.2?
Download
https://github.com/summerwind/actions-runner-controller/releases/download/v0.18.2/actions-runner-controller.yaml.Delete all
kind: runnersby settingreplicas: 0onrunnerdeployments.actions.summerwind.dev, as per @callum-tait-pbx comment.kubectl -n actions-runner-system edit runnerdeployments.actions.summerwind.dev gannett-org-runner-deployment-legacyDelete the following existing
actions.summerwind.devCRDs$> kubectl get crds | grep actions horizontalrunnerautoscalers.actions.summerwind.dev 2021-04-09T18:47:36Z runnerdeployments.actions.summerwind.dev 2021-04-09T18:47:37Z runnerreplicasets.actions.summerwind.dev 2021-04-09T18:47:39Z runners.actions.summerwind.dev 2021-04-09T18:47:42Z $> kubectl delete crds horizontalrunnerautoscalers.actions.summerwind.dev \ runnerdeployments.actions.summerwind.dev \ runnerreplicasets.actions.summerwind.dev \ runners.actions.summerwind.dev- Then
kubectl apply -ffilenamev0.18.2filename _( from step 1)_
kubectl apply -f actions-runner-controller.yaml
- Monitor/Watch
$> watch kubectl -n actions-runner-system get runners $> kubectl -n actions-runner-system logs -f controller-manager-844f8686f6-tfm6b -c manager
Let me know what you think.
Thank you,
laurentiuspurba
on 14 Apr 2021
Hello @mumoshu and @callum-tait-pbx
What do you think about my upgrade steps that I put here.
Really appreciate your input and comments on this.
laurentiuspurba
on 15 Apr 2021
So, I did follow the step-by-step instruction as per my previous comment.
But, I had to add more steps
- After _step 5_, I had to create
kind: RunnerDeployment; gather all manifest file(s) related to thiskind: RunnerDeployment - But before applying that
RunnerDeploymentfile, I had to removevolumeMounts:andvolumens:as per this github issue.
My concern is if I want to deploy or upgrade my production environment, there will be a downtime that has to be considered.
CMIIW.
laurentiuspurba
on 15 Apr 2021
@laurentiuspurba Hey! I believe that steps 1 to 3 are not necessary. You'd need those hacks only when you broke the installation by upgrading the controller without successfully upgrading the CRDs.
In the steps 4 though, you'd better use kubectl replace for upgrading CRDs.
Also- do you have some experience using K8s kind to bring up your local K8s cluster for testing? I'd suggest you to test the procedure with modified step 4 plus step 5 locally before going production. Also, if you omit steps 1 to 3, there shouldn't be any downtime. (I thought I've successfully upgraded the controller that way without any downtime when I verified https://github.com/summerwind/actions-runner-controller/issues/400#issuecomment-802398832
mumoshu
on 16 Apr 2021
I had to remove volumeMounts: and volumens:
This sounds like a blocker to me- would you like me to enhance the controller so that any extraneous volume/mount to /runner is just ignored with a warning?
Gotcha. I thought this is fine when you removed steps 1 to 3, because the controller is programmed to remove the old, working runner pods only after it successfully created new runner pods.
mumoshu
on 16 Apr 2021
@mumoshu - Let me give you some context on my installation.
I use helm template ./helm-charts/actions-runner-controller command. And inside actions-runner-controller folder there are:
- Chart.yaml
- values
- templates/autoscaler.yaml
- templates/crds.yaml
- templates/deployment.yaml
- templates/secrets.yaml
Once the helm template is completed, it will generate manifest file, and then I run kubectl apply -f against that manifest file.
The first that I did the upgrade from v0.17.0 to v0.18.2, what I did was replacing templates/crds.yaml with v0.18.2 version. This caused the issue that I reported on my previous messages on this thread.
So, if I don't do steps 1 - 3 from instructions that I sent, how should I do the upgrade?
laurentiuspurba
on 16 Apr 2021
Hello @mumoshu and @callum-tait-pbx
I finally nuked existing installation (_just got back from days off_), and then re-generated the manifest file and re-applied that file that was configured with new testing Github token.
Currently,
version 0.17.0is up and running, and I would likt to upgrade tov0.18.2.Do you mind reviewing the following steps to upgrade to
v0.18.2?1. Download `https://github.com/summerwind/actions-runner-controller/releases/download/v0.18.2/actions-runner-controller.yaml`. 2. Delete all `kind: runners` by setting `replicas: 0` on `runnerdeployments.actions.summerwind.dev`, as per @callum-tait-pbx [comment](https://github.com/summerwind/actions-runner-controller/issues/418#issuecomment-815583543).kubectl -n actions-runner-system edit runnerdeployments.actions.summerwind.dev gannett-org-runner-deployment-legacy1. Delete the following existing `actions.summerwind.dev` CRDs$> kubectl get crds | grep actions horizontalrunnerautoscalers.actions.summerwind.dev 2021-04-09T18:47:36Z runnerdeployments.actions.summerwind.dev 2021-04-09T18:47:37Z runnerreplicasets.actions.summerwind.dev 2021-04-09T18:47:39Z runners.actions.summerwind.dev 2021-04-09T18:47:42Z $> kubectl delete crds horizontalrunnerautoscalers.actions.summerwind.dev \ runnerdeployments.actions.summerwind.dev \ runnerreplicasets.actions.summerwind.dev \ runners.actions.summerwind.dev1. Then `kubectl apply -f ` filename `v0.18.2` filename _( from step 1)_kubectl apply -f actions-runner-controller.yaml1. Monitor/Watch$> watch kubectl -n actions-runner-system get runners $> kubectl -n actions-runner-system logs -f controller-manager-844f8686f6-tfm6b -c managerLet me know what you think.
Thank you,
This is the process I am following with my envs tooling (helsman + helm). I have been using the Helm chart since the first couple of releases. My exact process is:
- Disable my runner chart and controller chart in my helmsman file via
enabled: false. This will uninstall the 2 charts sequentially doing the runner chart first (we have it configured that way) - Once complete there will be runners left on the box as it never seems to successfully uninstall the runners. I just use
kubectlto delete the the runner kinds POSTing to the API as I described before - Delete the CRDs using
kubectl - Update my helmsman file to deploy the new version chart and redeploy the runners via the
enabled: trueattribute deploying the CRDs and controller first, then the runners
Looks like it's the same process as you have described just with my environments specific tooling.
callum-tait-pbx
on 17 Apr 2021
The first that I did the upgrade from v0.17.0 to v0.18.2, what I did was replacing templates/crds.yaml with v0.18.2 version. This caused the issue that I reported on my previous messages on this thread.
@laurentiuspurba Does this mean that you replaced templates/crds.yaml "only" and run helm template ./chart | kubectl apply -f - hoping it would only upgrade CRDs first?
mumoshu
on 18 Apr 2021
Related issues
BrendanGalloway
·
3Comments
raj-saxena
·
5Comments
callum-tait-pbx
·
9Comments
kaykhancheckpoint
·
4Comments
jeffrey-kinesso
·
5Comments