intel / trusted-certificate-issuer

Trusted Certificate Service (TCS) is a K8s service to protect signing keys using Intel's SGX technology. K8s CSR and cert-manager CR APIs are both supported. TCS also contains integration samples for Istio service mesh and Key Management Reference Application (KMRA).
Apache License 2.0
29 stars 15 forks source link

TCS panicked when example CA cert and Key were mismatched #44

Closed snackewm closed 2 years ago

snackewm commented 2 years ago

Using latest main branch (with label PR added), the TCS controller was observed to be restarting due to a panic.

The issue apparently was a misconfiguration of KMRA where one of the example Cert and Key were mismatched (the problem went away after removing and reconfiguring KMRA with a matching CA Cert and Key).

But, in the interest of not having TCS crash, here is the TCS log (a few extra debug log entries starting with "Provision Signer ..." were added to assist finding the configuration problem).

$ kubectl -n tcs-issuer logs -p --timestamps --tail=1000 $(kubectl -n tcs-issuer get pod -l control-plane=tcs-issuer --template '{{range .items}}{{.metadata.name}}{{"\n"}}{{end}}')
Defaulted container "tcs-issuer" out of: tcs-issuer, init (init)
2022-08-09T17:45:08.911806595Z 1.6600671089113495e+09   INFO    controller-runtime.metrics      Metrics server is starting to listen    {"addr": ":8082"}
2022-08-09T17:45:09.109855651Z 1.6600671091095202e+09   INFO    SGX     Initiating p11Session...
2022-08-09T17:45:09.110906059Z 1.6600671091106207e+09   LEVEL(-2)       setup   SGX initialization SUCCESS
2022-08-09T17:45:09.110935704Z 1.6600671091107883e+09   INFO    setup   starting manager
2022-08-09T17:45:09.111970007Z 1.6600671091115575e+09   INFO    Starting server {"kind": "health probe", "addr": "[::]:8083"}
2022-08-09T17:45:09.111998044Z 1.660067109111566e+09    INFO    Starting server {"path": "/metrics", "kind": "metrics", "addr": "[::]:8082"}
2022-08-09T17:45:09.112007150Z I0809 17:45:09.111487       1 leaderelection.go:248] attempting to acquire leader lease tcs-issuer/bb9c3a43.sgx.intel.com...
2022-08-09T17:45:25.593663301Z I0809 17:45:25.593327       1 leaderelection.go:258] successfully acquired lease tcs-issuer/bb9c3a43.sgx.intel.com
2022-08-09T17:45:25.594053181Z 1.6600671255934465e+09   DEBUG   events  Normal  {"object": {"kind":"ConfigMap","namespace":"tcs-issuer","name":"bb9c3a43.sgx.intel.com","uid":"c46b198a-87f8-4e73-a6ca-4096d3d81a9b","apiVersion":"v1","resourceVersion":"8088218"}, "reason": "LeaderElection", "message": "tcs-controller-6d856b7976-jb58f_a5698a2b-9b17-4eea-93a2-f9bfbfb87019 became leader"}
2022-08-09T17:45:25.594093014Z 1.6600671255936673e+09   DEBUG   events  Normal  {"object": {"kind":"Lease","namespace":"tcs-issuer","name":"bb9c3a43.sgx.intel.com","uid":"ab98d264-47ce-4ad4-b8b9-08fa4a434ec1","apiVersion":"coordination.k8s.io/v1","resourceVersion":"8088219"}, "reason": "LeaderElection", "message": "tcs-controller-6d856b7976-jb58f_a5698a2b-9b17-4eea-93a2-f9bfbfb87019 became leader"}
2022-08-09T17:45:25.594102592Z 1.6600671255936642e+09   INFO    controller.tcsissuer    Starting EventSource    {"reconciler group": "tcs.intel.com", "reconciler kind": "TCSIssuer", "source": "kind source: *v1alpha1.TCSIssuer"}
2022-08-09T17:45:25.594110945Z 1.6600671255937197e+09   INFO    controller.certificatesigningrequest    Starting EventSource    {"reconciler group": "certificates.k8s.io", "reconciler kind": "CertificateSigningRequest", "source": "kind source: *v1.CertificateSigningRequest"}
2022-08-09T17:45:25.594118719Z 1.6600671255937765e+09   INFO    controller.tcsissuer    Starting Controller     {"reconciler group": "tcs.intel.com", "reconciler kind": "TCSIssuer"}
2022-08-09T17:45:25.594126397Z 1.660067125593806e+09    INFO    controller.certificatesigningrequest    Starting Controller     {"reconciler group": "certificates.k8s.io", "reconciler kind": "CertificateSigningRequest"}
2022-08-09T17:45:25.596851825Z 1.6600671255963366e+09   INFO    controller.tcsclusterissuer     Starting EventSource    {"reconciler group": "tcs.intel.com", "reconciler kind": "TCSClusterIssuer", "source": "kind source: *v1alpha1.TCSClusterIssuer"}
2022-08-09T17:45:25.596881268Z 1.660067125596285e+09    INFO    controller.certificaterequest   Starting EventSource    {"reconciler group": "cert-manager.io", "reconciler kind": "CertificateRequest", "source": "kind source: *v1.CertificateRequest"}
2022-08-09T17:45:25.596889955Z 1.6600671255965576e+09   INFO    controller.tcsclusterissuer     Starting Controller     {"reconciler group": "tcs.intel.com", "reconciler kind": "TCSClusterIssuer"}
2022-08-09T17:45:25.596897302Z 1.6600671255965781e+09   INFO    controller.certificaterequest   Starting Controller     {"reconciler group": "cert-manager.io", "reconciler kind": "CertificateRequest"}
2022-08-09T17:45:25.696475853Z 1.6600671256960783e+09   INFO    controller.tcsissuer    Starting workers        {"reconciler group": "tcs.intel.com", "reconciler kind": "TCSIssuer", "worker count": 1}
2022-08-09T17:45:25.798160624Z 1.6600671257977512e+09   INFO    SGX     Generating quote keypair...     {"forSigner": "tcsissuer.tcs.intel.com/sandbox.my-ca"}
2022-08-09T17:45:25.799407530Z 1.6600671257990184e+09   INFO    controller.certificatesigningrequest    Starting workers        {"reconciler group": "certificates.k8s.io", "reconciler kind": "CertificateSigningRequest", "worker count": 1}
2022-08-09T17:45:25.799463197Z 1.6600671257991374e+09   INFO    controller.tcsclusterissuer     Starting workers        {"reconciler group": "tcs.intel.com", "reconciler kind": "TCSClusterIssuer", "worker count": 1}
2022-08-09T17:45:25.799472749Z 1.6600671257991598e+09   INFO    controller.certificaterequest   Starting workers        {"reconciler group": "cert-manager.io", "reconciler kind": "CertificateRequest", "worker count": 1}
2022-08-09T17:45:25.799549304Z 1.660067125799438e+09    INFO    controllers.CertificateRequest  Reconcile       {"req": "inteldeviceplugins-system/inteldeviceplugins-serving-cert-2bz9w"}
2022-08-09T17:45:28.014446204Z 1.6600671280140276e+09   INFO    SGX     Generating Quote...
2022-08-09T17:45:28.085921380Z 1.6600671280855465e+09   INFO    controller.tcsissuer    Initiating quote attestation    {"reconciler group": "tcs.intel.com", "reconciler kind": "TCSIssuer", "name": "my-ca", "namespace": "sandbox", "signer": "tcsissuer.tcs.intel.com/sandbox.my-ca"}
2022-08-09T17:45:28.573114837Z 1.6600671285726042e+09   INFO    SGX     Provision Signer        {"signerName": "tcsissuer.tcs.intel.com/sandbox.my-ca"}
2022-08-09T17:45:28.573149892Z 1.660067128572742e+09    INFO    SGX     Provision Signer signers were nil       {"signerName": "tcsissuer.tcs.intel.com/sandbox.my-ca"}
2022-08-09T17:45:28.715584362Z 1.6600671287152412e+09   INFO    SGX     Unwrapped SWK Key successfully
2022-08-09T17:45:28.916326348Z 1.6600671289159918e+09   INFO    SGX     Unwrapped PWK Key successfully
2022-08-09T17:45:29.025658647Z 1.6600671290254097e+09   INFO    SGX     Unwrapped Public Key successfully
2022-08-09T17:45:29.622418096Z 1.6600671296220675e+09   INFO    SGX     Provision Signer signers validate CA failed     {"error": "mismatched CA key and certificate"}
2022-08-09T17:45:29.686201918Z panic: interface conversion: interface is nil, not crypto11.Signer
2022-08-09T17:45:29.686244322Z
2022-08-09T17:45:29.686256345Z goroutine 448 [running]:
2022-08-09T17:45:29.686267707Z github.com/intel/trusted-certificate-issuer/internal/sgx.(*SgxContext).removeSignerInToken(0xc000b92780, 0xc0002fe230)
2022-08-09T17:45:29.686279177Z  /workspace/internal/sgx/sgx.go:255 +0xc5
2022-08-09T17:45:29.686293447Z github.com/intel/trusted-certificate-issuer/internal/sgx.(*SgxContext).ProvisionSigner(0xc000b92780, {0xc000c11b60, 0x804}, {0xc000312400, 0x890, 0x891}, 0xc000256580)
2022-08-09T17:45:29.686305446Z  /workspace/internal/sgx/sgx.go:351 +0x80e
2022-08-09T17:45:29.686313282Z github.com/intel/trusted-certificate-issuer/controllers.(*IssuerReconciler).provisionSigner(0xc000b929c0, {0x1a2a9d8, 0xc000c1f4d0}, {0xc000c11b60, 0x25}, {0xc000d82ec7, 0x5}, {0xc000d82ea5, 0x7})
2022-08-09T17:45:29.686336863Z  /workspace/controllers/issuer_controller.go:308 +0x43c
2022-08-09T17:45:29.686350837Z github.com/intel/trusted-certificate-issuer/controllers.(*IssuerReconciler).Reconcile(0xc000b929c0, {0x1a2a9d8, 0xc000c1f4d0}, {{{0xc0007a07a0, 0x1739580}, {0xc0007a0796, 0x30}}})
2022-08-09T17:45:29.686358002Z  /workspace/controllers/issuer_controller.go:173 +0x1305
2022-08-09T17:45:29.686365785Z sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Reconcile(0xc0003071e0, {0x1a2a9d8, 0xc000c1f440}, {{{0xc0007a07a0, 0x1739580}, {0xc0007a0796, 0x417f34}}})
2022-08-09T17:45:29.686373168Z  /workspace/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller/controller.go:114 +0x26f
2022-08-09T17:45:29.686380365Z sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler(0xc0003071e0, {0x1a2a930, 0xc0002e9100}, {0x16796e0, 0xc000e815c0})
2022-08-09T17:45:29.686387161Z  /workspace/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller/controller.go:311 +0x33e
2022-08-09T17:45:29.686417767Z sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem(0xc0003071e0, {0x1a2a930, 0xc0002e9100})
2022-08-09T17:45:29.686449993Z  /workspace/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller/controller.go:266 +0x205
2022-08-09T17:45:29.686459051Z sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2.2()
2022-08-09T17:45:29.686468217Z  /workspace/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller/controller.go:227 +0x85
2022-08-09T17:45:29.686476796Z created by sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2
2022-08-09T17:45:29.686485232Z  /workspace/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller/controller.go:223 +0x357
avalluri commented 2 years ago

@snackewm Thanks for reporting the issue, https://github.com/intel/trusted-certificate-issuer/pull/45 supposed to fix this.