[Profile Controller] IAM Plugin AnnotateOnly panic

[sergeyshevch]

/kind bug

What steps did you take and what happened: [A clear and concise description of what the bug is.]

Specify next plugin on profile CRD

- kind: AwsIamForServiceAccount
   spec:
     AnnotateOnly: "true"
     awsIamRole: my-role

Profile controller will fail with panic because of "true". If we specify true all works correctly

Profile controller logs:

1.6766436904558976e+09    DPANIC    controllers.Profile    odd number of arguments passed as key-value pairs for logging    {"profile": "kubeflow-group-analytics", "ignored key": "json: cannot unmarshal string into Go struct field AwsIAMForServiceAccount.AnnotateOnly of type bool"}
github.com/kubeflow/kubeflow/components/profile-controller/controllers.(*ProfileReconciler).Reconcile
    /workspace/controllers/profile_controller.go:286
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Reconcile
    /go/pkg/mod/sigs.k8s.io/controller-runtime@v0.12.1/pkg/internal/controller/controller.go:121
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler
    /go/pkg/mod/sigs.k8s.io/controller-runtime@v0.12.1/pkg/internal/controller/controller.go:320
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem
    /go/pkg/mod/sigs.k8s.io/controller-runtime@v0.12.1/pkg/internal/controller/controller.go:273
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2.2
    /go/pkg/mod/sigs.k8s.io/controller-runtime@v0.12.1/pkg/internal/controller/controller.go:234
1.6766436904559453e+09    INFO    Observed a panic in reconciler: odd number of arguments passed as key-value pairs for logging    {"controller": "profile", "controllerGroup": "kubeflow.org", "controllerKind": "Profile", "profile": {"name":"kubeflow-group-analytics"}, "namespace": "", "name": "kubeflow-group-analytics", "reconcileID": "f2e4919e-666c-4ad2-84c2-cdcc5c9051f4"}
panic: odd number of arguments passed as key-value pairs for logging [recovered]
    panic: odd number of arguments passed as key-value pairs for logging

goroutine 380 [running]:
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Reconcile.func1()
    /go/pkg/mod/sigs.k8s.io/controller-runtime@v0.12.1/pkg/internal/controller/controller.go:118 +0x1f4
panic({0x1772fc0, 0xc0007a8280})
    /usr/local/go/src/runtime/panic.go:1038 +0x215
go.uber.org/zap/zapcore.(*CheckedEntry).Write(0xc000dd40c0, {0xc0000f6480, 0x1, 0x1})
    /go/pkg/mod/go.uber.org/zap@v1.19.1/zapcore/entry.go:232 +0x446
go.uber.org/zap.(*Logger).DPanic(0x1a04125, {0x1a67b13, 0x17ccac0}, {0xc0000f6480, 0x1, 0x1})
    /go/pkg/mod/go.uber.org/zap@v1.19.1/logger.go:220 +0x59
github.com/go-logr/zapr.(*zapLogger).handleFields(0xc000b40c30, 0x0, {0xc000b40d80, 0x3, 0x40aedd}, {0x0, 0x18ed4a0, 0x1})
    /go/pkg/mod/github.com/go-logr/zapr@v1.2.0/zapr.go:145 +0xdea
github.com/go-logr/zapr.(*zapLogger).Info(0xc000b40c30, 0x0, {0x1a1b460, 0x0}, {0xc000b40d80, 0x3, 0x3})
    /go/pkg/mod/github.com/go-logr/zapr@v1.2.0/zapr.go:198 +0x8d
github.com/go-logr/logr.Logger.Info({{0x1de61c8, 0xc000b40c30}, 0x2}, {0x1a1b460, 0x1b}, {0xc000b40d80, 0x3, 0x3})
    /go/pkg/mod/github.com/go-logr/logr@v1.2.0/logr.go:249 +0xd0
github.com/kubeflow/kubeflow/components/profile-controller/controllers.(*ProfileReconciler).GetPluginSpec(0xc0001ea3f0, 0xc000579340)
    /workspace/controllers/profile_controller.go:681 +0x578
github.com/kubeflow/kubeflow/components/profile-controller/controllers.(*ProfileReconciler).Reconcile(0xc0001ea3f0, {0x1dc7798, 0xc000b542a0}, {{{0x0, 0x0}, {0xc000ad05b8, 0x18}}})
    /workspace/controllers/profile_controller.go:286 +0x1a8e
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Reconcile(0x1dc76f0, {0x1dc7798, 0xc000b542a0}, {{{0x0, 0x1931c60}, {0xc000ad05b8, 0x40edbd}}})
    /go/pkg/mod/sigs.k8s.io/controller-runtime@v0.12.1/pkg/internal/controller/controller.go:121 +0xd1
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler(0xc000190fa0, {0x1dc76f0, 0xc000701c00}, {0x1857c40, 0xc00070e5e0})
    /go/pkg/mod/sigs.k8s.io/controller-runtime@v0.12.1/pkg/internal/controller/controller.go:320 +0x33c
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem(0xc000190fa0, {0x1dc76f0, 0xc000701c00})
    /go/pkg/mod/sigs.k8s.io/controller-runtime@v0.12.1/pkg/internal/controller/controller.go:273 +0x205
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2.2()
    /go/pkg/mod/sigs.k8s.io/controller-runtime@v0.12.1/pkg/internal/controller/controller.go:234 +0x85
created by sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2
    /go/pkg/mod/sigs.k8s.io/controller-runtime@v0.12.1/pkg/internal/controller/controller.go:230 +0x36f
Stream closed EOF for kubeflow/profiles-deployment-dc8f57967-9nqdj (manager)

What did you expect to happen:

All works without panic or raise an error on creating profile with incorrect plugin

Anything else you would like to add: [Miscellaneous information that will assist in solving the issue.]

Environment:

• Kubeflow version: (version number can be found at the bottom left corner of the Kubeflow dashboard): docker.io/kubeflownotebookswg/profile-controller:latest
• kfctl version: (use kfctl version): NA
• Kubernetes platform: (e.g. minikube) EKS
• Kubernetes version: (use kubectl version): 1.24
• OS (e.g. from /etc/os-release): NA

[kimwnasptd]

cc @ryansteakley @surajkota could this be related to https://github.com/kubeflow/kubeflow/pull/6887?

[sergeyshevch]

Also, I should note that the field has a strange name. Maybe we need to use annotateOnly instead of AnnotateOnly

[sergeyshevch]

And documentations lack info about this plugin. I've found it's usage only on reading code

[surajkota]

I will let Ryan look into this, this might be a side affect of consuming the plugin as runtime.RawExtension and then marshalling it.

I propose splitting this issue into 2 tasks -

• changing the AnnotateOnly to annotateOnly asap and adding documentation which explains the parameter and default value before 1.7 release. I agree with the comment above. This will help prevent breaking changes in future.
• look into adding type checking for the fields using some go library or better way to load the struct to prevent panics (evaluate feasibility to fix before 1.7 release)

Let me know your thoughts and if you have ideas

[ryansteakley]

@sergeyshevch @kimwnasptd Created small pr to address the lack of documentation. https://github.com/kubeflow/kubeflow/pull/6996/files.

In regards to the name you can already choose to specify it as annotateOnly or AnnotateOnly in the yaml file. Additionally it is not possible to change the variable name in the go code from AnnotateOnly to annotateOnly as from the golang documentation it is not possible to lowercase it.

exported identifiers
An identifier may be exported to permit access to it from another package. An identifier is exported if both: the first character of the identifier's name is a Unicode uppercase letter

In the pr I have specified to the json that json:"annotateOnly,omitempty" instead of the previous value of json:"AnnotateOnly,omitempty", seems to make no practical difference however.

Finally for the value of "true" causing a panic this is expected behavior as the profile code is using json.unmarshal and the type is of bool. The unmarshal method cannot perform this action ""json: cannot unmarshal string into Go struct field AwsIAMForServiceAccount.AnnotateOnly of type bool".

To get around user specifying true or "true" we would need to implement a custom method to handle this.

[surajkota]

In regards to the name you can already choose to specify it as annotateOnly or AnnotateOnly in the yaml file.

Can you give more detail on this? is json tag is case insensitive?

[ryansteakley]

https://pkg.go.dev/encoding/json#Unmarshal, specifies that, "To unmarshal JSON into a struct, Unmarshal matches incoming object keys to the keys used by Marshal (either the struct field name or its tag), preferring an exact match but also accepting a case-insensitive match"

[surajkota]

Great!

[andreyvelich]

/transfer dashboard

[google-oss-prow[bot]]

@sergeyshevch: The label(s) kind/bug cannot be applied, because the repository doesn't have them.

In response to [this](https://github.com/kubeflow/dashboard/issues/24): >/kind bug > >**What steps did you take and what happened:** >[A clear and concise description of what the bug is.] > >Specify next plugin on profile CRD >``` >- kind: AwsIamForServiceAccount > spec: > AnnotateOnly: "true" > awsIamRole: my-role >``` > >Profile controller will fail with panic because of `"true"`. If we specify `true` all works correctly > >Profile controller logs: > >``` > >1.6766436904558976e+09 DPANIC controllers.Profile odd number of arguments passed as key-value pairs for logging {"profile": "kubeflow-group-analytics", "ignored key": "json: cannot unmarshal string into Go struct field AwsIAMForServiceAccount.AnnotateOnly of type bool"} >github.com/kubeflow/kubeflow/components/profile-controller/controllers.(*ProfileReconciler).Reconcile > /workspace/controllers/profile_controller.go:286 >sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Reconcile > /go/pkg/mod/sigs.k8s.io/controller-runtime@v0.12.1/pkg/internal/controller/controller.go:121 >sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler > /go/pkg/mod/sigs.k8s.io/controller-runtime@v0.12.1/pkg/internal/controller/controller.go:320 >sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem > /go/pkg/mod/sigs.k8s.io/controller-runtime@v0.12.1/pkg/internal/controller/controller.go:273 >sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2.2 > /go/pkg/mod/sigs.k8s.io/controller-runtime@v0.12.1/pkg/internal/controller/controller.go:234 >1.6766436904559453e+09 INFO Observed a panic in reconciler: odd number of arguments passed as key-value pairs for logging {"controller": "profile", "controllerGroup": "kubeflow.org", "controllerKind": "Profile", "profile": {"name":"kubeflow-group-analytics"}, "namespace": "", "name": "kubeflow-group-analytics", "reconcileID": "f2e4919e-666c-4ad2-84c2-cdcc5c9051f4"} >panic: odd number of arguments passed as key-value pairs for logging [recovered] > panic: odd number of arguments passed as key-value pairs for logging > >goroutine 380 [running]: >sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Reconcile.func1() > /go/pkg/mod/sigs.k8s.io/controller-runtime@v0.12.1/pkg/internal/controller/controller.go:118 +0x1f4 >panic({0x1772fc0, 0xc0007a8280}) > /usr/local/go/src/runtime/panic.go:1038 +0x215 >go.uber.org/zap/zapcore.(*CheckedEntry).Write(0xc000dd40c0, {0xc0000f6480, 0x1, 0x1}) > /go/pkg/mod/go.uber.org/zap@v1.19.1/zapcore/entry.go:232 +0x446 >go.uber.org/zap.(*Logger).DPanic(0x1a04125, {0x1a67b13, 0x17ccac0}, {0xc0000f6480, 0x1, 0x1}) > /go/pkg/mod/go.uber.org/zap@v1.19.1/logger.go:220 +0x59 >github.com/go-logr/zapr.(*zapLogger).handleFields(0xc000b40c30, 0x0, {0xc000b40d80, 0x3, 0x40aedd}, {0x0, 0x18ed4a0, 0x1}) > /go/pkg/mod/github.com/go-logr/zapr@v1.2.0/zapr.go:145 +0xdea >github.com/go-logr/zapr.(*zapLogger).Info(0xc000b40c30, 0x0, {0x1a1b460, 0x0}, {0xc000b40d80, 0x3, 0x3}) > /go/pkg/mod/github.com/go-logr/zapr@v1.2.0/zapr.go:198 +0x8d >github.com/go-logr/logr.Logger.Info({{0x1de61c8, 0xc000b40c30}, 0x2}, {0x1a1b460, 0x1b}, {0xc000b40d80, 0x3, 0x3}) > /go/pkg/mod/github.com/go-logr/logr@v1.2.0/logr.go:249 +0xd0 >github.com/kubeflow/kubeflow/components/profile-controller/controllers.(*ProfileReconciler).GetPluginSpec(0xc0001ea3f0, 0xc000579340) > /workspace/controllers/profile_controller.go:681 +0x578 >github.com/kubeflow/kubeflow/components/profile-controller/controllers.(*ProfileReconciler).Reconcile(0xc0001ea3f0, {0x1dc7798, 0xc000b542a0}, {{{0x0, 0x0}, {0xc000ad05b8, 0x18}}}) > /workspace/controllers/profile_controller.go:286 +0x1a8e >sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Reconcile(0x1dc76f0, {0x1dc7798, 0xc000b542a0}, {{{0x0, 0x1931c60}, {0xc000ad05b8, 0x40edbd}}}) > /go/pkg/mod/sigs.k8s.io/controller-runtime@v0.12.1/pkg/internal/controller/controller.go:121 +0xd1 >sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler(0xc000190fa0, {0x1dc76f0, 0xc000701c00}, {0x1857c40, 0xc00070e5e0}) > /go/pkg/mod/sigs.k8s.io/controller-runtime@v0.12.1/pkg/internal/controller/controller.go:320 +0x33c >sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem(0xc000190fa0, {0x1dc76f0, 0xc000701c00}) > /go/pkg/mod/sigs.k8s.io/controller-runtime@v0.12.1/pkg/internal/controller/controller.go:273 +0x205 >sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2.2() > /go/pkg/mod/sigs.k8s.io/controller-runtime@v0.12.1/pkg/internal/controller/controller.go:234 +0x85 >created by sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2 > /go/pkg/mod/sigs.k8s.io/controller-runtime@v0.12.1/pkg/internal/controller/controller.go:230 +0x36f >Stream closed EOF for kubeflow/profiles-deployment-dc8f57967-9nqdj (manager) > > >``` > >**What did you expect to happen:** > >All works without panic or raise an error on creating profile with incorrect plugin > >**Anything else you would like to add:** >[Miscellaneous information that will assist in solving the issue.] > > >**Environment:** > >- Kubeflow version: (version number can be found at the bottom left corner of the Kubeflow dashboard): docker.io/kubeflownotebookswg/profile-controller:latest >- kfctl version: (use `kfctl version`): NA >- Kubernetes platform: (e.g. `minikube`) EKS >- Kubernetes version: (use `kubectl version`): 1.24 >- OS (e.g. from `/etc/os-release`): NA > Instructions for interacting with me using PR comments are available [here](https://git.k8s.io/community/contributors/guide/pull-requests.md). If you have questions or suggestions related to my behavior, please file an issue against the [kubernetes/test-infra](https://github.com/kubernetes/test-infra/issues/new?title=Prow%20issue:) repository.