Operator stopped working after 2 weeks

[xendren]

We have been running tests successfully using k6-operator for the past 2 weeks. It stopped working a few days ago, and all we can see is that the operator is not starting up any other worker pods. We were able to get some error messages to appear if we have the manager logs showing when we apply the k6 resource. Log messages with errors listed below:

2022-06-30T16:05:28.176Z INFO controller-runtime.metrics metrics server is starting to listen {"addr": "127.0.0.1:8080"}
--
Thu, Jun 30 2022 11:05:28 am | 2022-06-30T16:05:28.176Z INFO setup starting manager
Thu, Jun 30 2022 11:05:28 am | I0630 16:05:28.176806 1 leaderelection.go:242] attempting to acquire leader lease k6-operator-system/fcdfce80.io...
Thu, Jun 30 2022 11:05:28 am | 2022-06-30T16:05:28.177Z INFO controller-runtime.manager starting metrics server {"path": "/metrics"}
Thu, Jun 30 2022 11:05:28 am | I0630 16:05:28.193224 1 leaderelection.go:252] successfully acquired lease k6-operator-system/fcdfce80.io
Thu, Jun 30 2022 11:05:28 am | 2022-06-30T16:05:28.215Z DEBUG controller-runtime.manager.events Normal {"object": {"kind":"ConfigMap","namespace":"k6-operator-system","name":"fcdfce80.io","uid":"f77f81a2-3dfa-46be-b3a3-17e901bfc76d","apiVersion":"v1","resourceVersion":"154435981"}, "reason": "LeaderElection", "message": "k6-operator-controller-manager-8b685df4d-qxwb8_6f005008-e759-4dfc-9572-cd51d9ab2655 became leader"}
Thu, Jun 30 2022 11:05:28 am | 2022-06-30T16:05:28.215Z INFO controller Starting EventSource {"reconcilerGroup": "k6.io", "reconcilerKind": "K6", "controller": "k6", "source": "kind source: /, Kind="}
Thu, Jun 30 2022 11:05:28 am | 2022-06-30T16:05:28.416Z INFO controller Starting EventSource {"reconcilerGroup": "k6.io", "reconcilerKind": "K6", "controller": "k6", "source": "kind source: /, Kind="}
Thu, Jun 30 2022 11:05:28 am | 2022-06-30T16:05:28.516Z INFO controller Starting Controller {"reconcilerGroup": "k6.io", "reconcilerKind": "K6", "controller": "k6"}
Thu, Jun 30 2022 11:05:28 am | 2022-06-30T16:05:28.516Z INFO controller Starting workers {"reconcilerGroup": "k6.io", "reconcilerKind": "K6", "controller": "k6", "worker count": 1}
Thu, Jun 30 2022 11:08:02 am | 2022-06-30T16:08:02.957Z INFO controllers.K6 Reconcile(); stage = {"k6": "default/k6-sample"}
Thu, Jun 30 2022 11:08:02 am | 2022-06-30T16:08:02.957Z INFO controllers.K6 Initialize test {"k6": "default/k6-sample"}
Thu, Jun 30 2022 11:08:02 am | 2022-06-30T16:08:02.957Z INFO controllers.K6 Changing stage of K6 status to initialization {"k6": "default/k6-sample"}
Thu, Jun 30 2022 11:08:02 am | E0630 16:08:02.968007 1 runtime.go:78] Observed a panic: runtime.boundsError{x:0, y:0, signed:true, code:0x0} (runtime error: index out of range [0] with length 0)
Thu, Jun 30 2022 11:08:02 am | goroutine 231 [running]:
Thu, Jun 30 2022 11:08:02 am | k8s.io/apimachinery/pkg/util/runtime.logPanic({0x14d3e00?, 0xc000130c18})
Thu, Jun 30 2022 11:08:02 am | /go/pkg/mod/k8s.io/apimachinery@v0.18.6/pkg/util/runtime/runtime.go:74 +0x99
Thu, Jun 30 2022 11:08:02 am | k8s.io/apimachinery/pkg/util/runtime.HandleCrash({0x0, 0x0, 0xc000255640?})
Thu, Jun 30 2022 11:08:02 am | /go/pkg/mod/k8s.io/apimachinery@v0.18.6/pkg/util/runtime/runtime.go:48 +0x75
Thu, Jun 30 2022 11:08:02 am | panic({0x14d3e00, 0xc000130c18})
Thu, Jun 30 2022 11:08:02 am | /usr/local/go/src/runtime/panic.go:838 +0x207
Thu, Jun 30 2022 11:08:02 am | github.com/grafana/k6-operator/pkg/types.ParseCLI.func1(...)
Thu, Jun 30 2022 11:08:02 am | /workspace/pkg/types/types.go:135
Thu, Jun 30 2022 11:08:02 am | github.com/grafana/k6-operator/pkg/types.ParseCLI(0xc00098f518)
Thu, Jun 30 2022 11:08:02 am | /workspace/pkg/types/types.go:155 +0x465
Thu, Jun 30 2022 11:08:02 am | github.com/grafana/k6-operator/controllers.InitializeJobs({0x17cec80, 0xc0001aa000}, {0x17d0618?, 0xc00017c540?}, 0xc00098f400, 0xc000d14870)
Thu, Jun 30 2022 11:08:02 am | /workspace/controllers/k6_initialize.go:45 +0x15d
Thu, Jun 30 2022 11:08:02 am | github.com/grafana/k6-operator/controllers.(*K6Reconciler).Reconcile(0xc000d14870, {{{0xc000430e89, 0x7}, {0xc000430e74, 0x9}}})
Thu, Jun 30 2022 11:08:02 am | /workspace/controllers/k6_controller.go:63 +0x459
Thu, Jun 30 2022 11:08:02 am | sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler(0xc000d1c870, {0x1452d20?, 0xc000255640?})
Thu, Jun 30 2022 11:08:02 am | /go/pkg/mod/sigs.k8s.io/controller-runtime@v0.6.2/pkg/internal/controller/controller.go:235 +0x2a7
Thu, Jun 30 2022 11:08:02 am | sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem(0xc000d1c870)
Thu, Jun 30 2022 11:08:02 am | /go/pkg/mod/sigs.k8s.io/controller-runtime@v0.6.2/pkg/internal/controller/controller.go:209 +0xb7
Thu, Jun 30 2022 11:08:02 am | sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).worker(0xc00089c6a0?)
Thu, Jun 30 2022 11:08:02 am | /go/pkg/mod/sigs.k8s.io/controller-runtime@v0.6.2/pkg/internal/controller/controller.go:188 +0x25
Thu, Jun 30 2022 11:08:02 am | k8s.io/apimachinery/pkg/util/wait.BackoffUntil.func1(0x0?)
Thu, Jun 30 2022 11:08:02 am | /go/pkg/mod/k8s.io/apimachinery@v0.18.6/pkg/util/wait/wait.go:155 +0x3e
Thu, Jun 30 2022 11:08:02 am | k8s.io/apimachinery/pkg/util/wait.BackoffUntil(0x0?, {0x17ba7e0, 0xc000a47380}, 0x1, 0xc00061ee40)
Thu, Jun 30 2022 11:08:02 am | /go/pkg/mod/k8s.io/apimachinery@v0.18.6/pkg/util/wait/wait.go:156 +0xb6
Thu, Jun 30 2022 11:08:02 am | k8s.io/apimachinery/pkg/util/wait.JitterUntil(0x0?, 0x3b9aca00, 0x0, 0x0?, 0x0?)
Thu, Jun 30 2022 11:08:02 am | /go/pkg/mod/k8s.io/apimachinery@v0.18.6/pkg/util/wait/wait.go:133 +0x89
Thu, Jun 30 2022 11:08:02 am | k8s.io/apimachinery/pkg/util/wait.Until(0x0?, 0x0?, 0x0?)
Thu, Jun 30 2022 11:08:02 am | /go/pkg/mod/k8s.io/apimachinery@v0.18.6/pkg/util/wait/wait.go:90 +0x25
Thu, Jun 30 2022 11:08:02 am | created by sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func1
Thu, Jun 30 2022 11:08:02 am | /go/pkg/mod/sigs.k8s.io/controller-runtime@v0.6.2/pkg/internal/controller/controller.go:170 +0x39d
Thu, Jun 30 2022 11:08:02 am | panic: runtime error: index out of range [0] with length 0 [recovered]
Thu, Jun 30 2022 11:08:02 am | panic: runtime error: index out of range [0] with length 0
Thu, Jun 30 2022 11:08:02 am |  
Thu, Jun 30 2022 11:08:02 am | goroutine 231 [running]:
Thu, Jun 30 2022 11:08:02 am | k8s.io/apimachinery/pkg/util/runtime.HandleCrash({0x0, 0x0, 0xc000255640?})
Thu, Jun 30 2022 11:08:02 am | /go/pkg/mod/k8s.io/apimachinery@v0.18.6/pkg/util/runtime/runtime.go:55 +0xd8
Thu, Jun 30 2022 11:08:02 am | panic({0x14d3e00, 0xc000130c18})
Thu, Jun 30 2022 11:08:02 am | /usr/local/go/src/runtime/panic.go:838 +0x207
Thu, Jun 30 2022 11:08:02 am | github.com/grafana/k6-operator/pkg/types.ParseCLI.func1(...)
Thu, Jun 30 2022 11:08:02 am | /workspace/pkg/types/types.go:135
Thu, Jun 30 2022 11:08:02 am | github.com/grafana/k6-operator/pkg/types.ParseCLI(0xc00098f518)
Thu, Jun 30 2022 11:08:02 am | /workspace/pkg/types/types.go:155 +0x465
Thu, Jun 30 2022 11:08:02 am | github.com/grafana/k6-operator/controllers.InitializeJobs({0x17cec80, 0xc0001aa000}, {0x17d0618?, 0xc00017c540?}, 0xc00098f400, 0xc000d14870)
Thu, Jun 30 2022 11:08:02 am | /workspace/controllers/k6_initialize.go:45 +0x15d
Thu, Jun 30 2022 11:08:02 am | github.com/grafana/k6-operator/controllers.(*K6Reconciler).Reconcile(0xc000d14870, {{{0xc000430e89, 0x7}, {0xc000430e74, 0x9}}})
Thu, Jun 30 2022 11:08:02 am | /workspace/controllers/k6_controller.go:63 +0x459
Thu, Jun 30 2022 11:08:02 am | sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler(0xc000d1c870, {0x1452d20?, 0xc000255640?})
Thu, Jun 30 2022 11:08:02 am | /go/pkg/mod/sigs.k8s.io/controller-runtime@v0.6.2/pkg/internal/controller/controller.go:235 +0x2a7
Thu, Jun 30 2022 11:08:02 am | sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem(0xc000d1c870)
Thu, Jun 30 2022 11:08:02 am | /go/pkg/mod/sigs.k8s.io/controller-runtime@v0.6.2/pkg/internal/controller/controller.go:209 +0xb7
Thu, Jun 30 2022 11:08:02 am | sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).worker(0xc00089c6a0?)
Thu, Jun 30 2022 11:08:02 am | /go/pkg/mod/sigs.k8s.io/controller-runtime@v0.6.2/pkg/internal/controller/controller.go:188 +0x25
Thu, Jun 30 2022 11:08:02 am | k8s.io/apimachinery/pkg/util/wait.BackoffUntil.func1(0x0?)
Thu, Jun 30 2022 11:08:02 am | /go/pkg/mod/k8s.io/apimachinery@v0.18.6/pkg/util/wait/wait.go:155 +0x3e
Thu, Jun 30 2022 11:08:02 am | k8s.io/apimachinery/pkg/util/wait.BackoffUntil(0x0?, {0x17ba7e0, 0xc000a47380}, 0x1, 0xc00061ee40)
Thu, Jun 30 2022 11:08:02 am | /go/pkg/mod/k8s.io/apimachinery@v0.18.6/pkg/util/wait/wait.go:156 +0xb6
Thu, Jun 30 2022 11:08:02 am | k8s.io/apimachinery/pkg/util/wait.JitterUntil(0x0?, 0x3b9aca00, 0x0, 0x0?, 0x0?)
Thu, Jun 30 2022 11:08:02 am | /go/pkg/mod/k8s.io/apimachinery@v0.18.6/pkg/util/wait/wait.go:133 +0x89
Thu, Jun 30 2022 11:08:02 am | k8s.io/apimachinery/pkg/util/wait.Until(0x0?, 0x0?, 0x0?)
Thu, Jun 30 2022 11:08:02 am | /go/pkg/mod/k8s.io/apimachinery@v0.18.6/pkg/util/wait/wait.go:90 +0x25
Thu, Jun 30 2022 11:08:02 am | created by sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func1
Thu, Jun 30 2022 11:08:02 am | /go/pkg/mod/sigs.k8s.io/controller-runtime@v0.6.2/pkg/internal/controller/controller.go:170 +0x39d

[yorugac]

Hi @xendren, thanks for the bug report. Sadly, it's not at all clear how to reproduce it at the moment... What is the argument line that you're using? Did you change it? Did you restart the operator?
If operator has worked for 2 weeks straight with the same test arguments and then suddenly broke - that is very strange.

Either way, for now I pushed a fix for panic itself de57947 - please try to switch to the new latest image; perhaps, that'd help.

[gdcmarinho]

Any updates about it, @xendren?

[chrisduong]

I had the same problem because I had not pinned the Operator version, I had used latest, once I pinned to v0.0.8, the problem is gone.

[yorugac]

👋 There was a lot of changes in the operator since this bug report, including big changes in logic. I'm closing this issue for now; but if someone has info on how to re-produce this with recent version of the operator, please feel free to re-open.