kyverno: [Bug] verifyImages wrongly claims image is not signed

Kyverno Version

1.9.2

Description

I recently upgraded to kyverno 1.9.2 from 1.6.1 and face issues with the ImageVerify rule that got migrated with the update. I am trying to get a rule that would allow only signed images with a certain key to be deployed in my cluster.

The policy looks like this:

apiVersion: kyverno.io/v1
kind: ClusterPolicy
metadata:
  annotations:
    meta.helm.sh/release-name: kyverno-cluster-policies
    meta.helm.sh/release-namespace: kyverno
    policies.kyverno.io/category: Software Supply Chain Security, EKS Best Practices
    policies.kyverno.io/description: Check if the image to be launched in a dedicated
      pod is signed with our vault CA.
    policies.kyverno.io/minversion: 1.7.0
    policies.kyverno.io/severity: medium
    policies.kyverno.io/subject: Pod
    policies.kyverno.io/title: Cosign signature check
  labels:
    app.kubernetes.io/managed-by: Helm
  name: check-image-signature
spec:
  background: false
  rules:
  - exclude:
      any:
      - resources:
          selector:
            matchExpressions:
            - key: cosign-enforcement-enabled
              operator: In
              values:
              - "false"
    match:
      any:
      - resources:
          kinds:
          - Pod
          namespaceSelector:
            matchExpressions:
            - key: cosign-enforcement-enabled
              operator: In
              values:
              - "true"
    name: check-image-signature
    verifyImages:
    - attestors:
      - count: 1
        entries:
        - keys:
            publicKeys: REDACTED
            signatureAlgorithm: sha256
      imageReferences:
      - CORPORATE-REGISTRY/*
      mutateDigest: false
      required: true
      verifyDigest: false
  validationFailureAction: Enforce
  webhookTimeoutSeconds: 30

with this policy applied i try to create a pod

apiVersion: v1
kind: Pod
metadata:
  labels:
    run: test
  name: test
  namespace: test-tt
spec:
  containers:
  - image: CORPORATE-REGISTRY/tobias.trabelsi/heap-dump-service:4d01f64e2eb82e1e6d9f6bf4816d8044fa148433
    imagePullPolicy: IfNotPresent
    name: test
    resources: {}
    terminationMessagePath: /dev/termination-log
    terminationMessagePolicy: File
  dnsPolicy: ClusterFirst
  enableServiceLinks: true
  preemptionPolicy: PreemptLowerPriority
  priority: 0
  restartPolicy: Always
  schedulerName: default-scheduler
  securityContext: {}
  serviceAccount: default
  serviceAccountName: default
  terminationGracePeriodSeconds: 30

and get the error message:

Error from server: error when creating "test.yaml": admission webhook "validate.kyverno.svc-fail" denied the request:

policy Pod/test-tt/test for resource violation:

check-image-signature:
  check-image-signature: image is not verified

so naturally i tried to check if this is really the case as i am rather certain that this image is signed:

cosign verify CORPORATE-REGISTRY/tobias.trabelsi/heap-dump-service:4d01f64e2eb82e1e6d9f6bf4816d8044fa148433 --key=$HOME/tmp/cosign_test/cosign.pub.23

Verification for CORPORATE-REGISTRY/tobias.trabelsi/heap-dump-service:4d01f64e2eb82e1e6d9f6bf4816d8044fa148433 --
The following checks were performed on each of these signatures:
  - The cosign claims were validated
  - The signatures were verified against the specified public key

[{"critical":{"identity":{"docker-reference":"CORPORATE-REGISTRY/tobias.trabelsi/heap-dump-service"},"image":{"docker-manifest-digest":"sha256:b58e9c1b4c3f5d20d45c1f8f19eddb3d62c9ad0bb3dac9f50083ebbfb8d72281"},"type":"cosign container image signature"},"optional":null}]

So the image is signed and can be validated with the key that is also specified in the kyverno policy. I increased the verbosity in kyverno as specified in the troubleshooting guide to see the following logs:

I0324 15:14:37.527508       1 handlers.go:153] webhooks/resource/mutate "msg"="received an admission request in mutating webhook" "gvk"={"group":"","version":"v1","kind":"Pod"} "kind"="Pod" "name"="test" "namespace"="test-tt" "operation"="CREATE" "uid"="cd988e6c-cb86-45e6-8bae-bdd9d0dcab16" "user"={"username":"provisioning","groups":["system:masters","system:authenticated"]}
I0324 15:14:37.527695       1 handlers.go:160] webhooks/resource/mutate "msg"="processing policies for mutate admission request" "gvk"={"group":"","version":"v1","kind":"Pod"} "kind"="Pod" "mutatePolicies"=2 "name"="test" "namespace"="test-tt" "operation"="CREATE" "uid"="cd988e6c-cb86-45e6-8bae-bdd9d0dcab16" "user"={"username":"provisioning","groups":["system:masters","system:authenticated"]} "verifyImagesPolicies"=1
I0324 15:14:37.527832       1 roleRef.go:101]  "msg"="found a matched user/group 'system:authenticated' in request userInfo: [system:masters system:authenticated provisioning]"
I0324 15:14:37.527849       1 roleRef.go:101]  "msg"="found a matched user/group 'system:authenticated' in request userInfo: [system:masters system:authenticated provisioning]"
I0324 15:14:37.528357       1 roleRef.go:101]  "msg"="found a matched user/group 'system:masters' in request userInfo: [system:masters system:authenticated provisioning]"
I0324 15:14:37.528423       1 roleRef.go:101]  "msg"="found a matched user/group 'system:authenticated' in request userInfo: [system:masters system:authenticated provisioning]"
I0324 15:14:37.530535       1 context.go:234] context "msg"="Adding service account" "service account name"="" "service account namespace"=""
I0324 15:14:37.530898       1 context.go:278]  "msg"="updated image info" "images"={"containers":{"test":{"registry":"CORPORATE-REGISTRY","name":"heap-dump-service","path":"tobias.trabelsi/heap-dump-service","tag":"4d01f64e2eb82e1e6d9f6bf4816d8044fa148433"}}}
I0324 15:14:37.531870       1 utils.go:29]  "msg"="applied JSON patch" "patch"=[{"op":"replace","path":"/spec/containers/0/image","value":"CORPORATE-REGISTRY/tobias.trabelsi/heap-dump-service:4d01f64e2eb82e1e6d9f6bf4816d8044fa148433"}]
I0324 15:14:37.534406       1 mutation.go:109] webhooks/resource/mutate "msg"="applying policy mutate rules" "gvk"={"group":"","version":"v1","kind":"Pod"} "kind"="Pod" "name"="test" "namespace"="test-tt" "operation"="CREATE" "policy"="log4j-mitigation-env-var" "uid"="cd988e6c-cb86-45e6-8bae-bdd9d0dcab16" "user"={"username":"provisioning","groups":["system:masters","system:authenticated"]}
I0324 15:14:37.534486       1 mutation.go:39] EngineMutate "msg"="start mutate policy processing" "kind"="Pod" "name"="test" "namespace"="test-tt" "policy"="log4j-mitigation-env-var" "startTime"="2023-03-24T15:14:37.534423373Z"
I0324 15:14:37.536081       1 mutation.go:82] EngineMutate "msg"="processing mutate rule" "applyRules"="All" "kind"="Pod" "name"="test" "namespace"="test-tt" "policy"="log4j-mitigation-env-var" "rule"="log4j-mitigation-env-var-inject"
I0324 15:14:37.542158       1 mutation.go:137] EngineMutate "msg"="apply rule to resource" "kind"="Pod" "name"="test" "namespace"="test-tt" "policy"="log4j-mitigation-env-var" "resource name"="test" "resource namespace"="test-tt" "rule"="log4j-mitigation-env-var-inject"
I0324 15:14:37.560437       1 strategicMergePatch.go:21] EngineMutate/ProcessStrategicMergePatch "msg"="started applying strategicMerge patch" "kind"="Pod" "name"="test" "namespace"="test-tt" "policy"="log4j-mitigation-env-var" "rule"="log4j-mitigation-env-var-inject" "startTime"="2023-03-24T15:14:37.560392051Z"
I0324 15:14:37.561954       1 strategicPreprocessing.go:168] EngineMutate/ProcessStrategicMergePatch "msg"="anchor mismatch" "kind"="Pod" "name"="test" "namespace"="test-tt" "policy"="log4j-mitigation-env-var" "reason"="condition failed: could not found \"name\" key in the resource" "rule"="log4j-mitigation-env-var-inject"
I0324 15:14:37.562518       1 strategicMergePatch.go:100] EngineMutate/ProcessStrategicMergePatch "msg"="applying strategic merge patch" "kind"="Pod" "name"="test" "namespace"="test-tt" "patch"="{\"spec\": {\"containers\": [{\"env\": [{\"name\": \"LOG4J_FORMAT_MSG_NO_LOOKUPS\", \"value\": \"true\"}], name: \"test\"}]}}\n" "policy"="log4j-mitigation-env-var" "rule"="log4j-mitigation-env-var-inject"
I0324 15:14:37.566208       1 strategicMergePatch.go:28] EngineMutate/ProcessStrategicMergePatch "msg"="finished applying strategicMerge patch" "kind"="Pod" "name"="test" "namespace"="test-tt" "policy"="log4j-mitigation-env-var" "processingTime"="5.793442ms" "rule"="log4j-mitigation-env-var-inject"
I0324 15:14:37.570208       1 mutation.go:120] webhooks/resource/mutate "msg"="mutation rules from policy applied successfully" "gvk"={"group":"","version":"v1","kind":"Pod"} "kind"="Pod" "name"="test" "namespace"="test-tt" "operation"="CREATE" "policy"="log4j-mitigation-env-var" "rules"=["log4j-mitigation-env-var-inject"] "uid"="cd988e6c-cb86-45e6-8bae-bdd9d0dcab16" "user"={"username":"provisioning","groups":["system:masters","system:authenticated"]}
I0324 15:14:37.570564       1 mutation.go:109] webhooks/resource/mutate "msg"="applying policy mutate rules" "gvk"={"group":"","version":"v1","kind":"Pod"} "kind"="Pod" "name"="test" "namespace"="test-tt" "operation"="CREATE" "policy"="scheduler-substitution" "uid"="cd988e6c-cb86-45e6-8bae-bdd9d0dcab16" "user"={"username":"provisioning","groups":["system:masters","system:authenticated"]}
I0324 15:14:37.570901       1 mutation.go:39] EngineMutate "msg"="start mutate policy processing" "kind"="Pod" "name"="test" "namespace"="test-tt" "policy"="scheduler-substitution" "startTime"="2023-03-24T15:14:37.570606868Z"
I0324 15:14:37.571720       1 mutation.go:70] EngineMutate "msg"="rule not matched" "kind"="Pod" "name"="test" "namespace"="test-tt" "policy"="scheduler-substitution" "reason"="rule scheduler-substitution not matched:\n 1. namespace selector does not match" "rule"="scheduler-substitution"
I0324 15:14:37.572190       1 annotations.go:137] webhooks/resource/mutate "msg"="annotation value prepared" "gvk"={"group":"","version":"v1","kind":"Pod"} "kind"="Pod" "name"="test" "namespace"="test-tt" "operation"="CREATE" "patches"=[{"rulename":"log4j-mitigation-env-var-inject","op":"add","path":"/spec/containers/0/env"}] "uid"="cd988e6c-cb86-45e6-8bae-bdd9d0dcab16" "user"={"username":"provisioning","groups":["system:masters","system:authenticated"]}
I0324 15:14:37.572523       1 mutation.go:180] webhooks/resource/mutate "msg"="created patches" "count"=2 "gvk"={"group":"","version":"v1","kind":"Pod"} "kind"="Pod" "name"="test" "namespace"="test-tt" "operation"="CREATE" "uid"="cd988e6c-cb86-45e6-8bae-bdd9d0dcab16" "user"={"username":"provisioning","groups":["system:masters","system:authenticated"]}
I0324 15:14:37.573581       1 roleRef.go:101]  "msg"="found a matched user/group 'system:authenticated' in request userInfo: [system:masters system:authenticated provisioning]"
I0324 15:14:37.573615       1 roleRef.go:101]  "msg"="found a matched user/group 'system:authenticated' in request userInfo: [system:masters system:authenticated provisioning]"
I0324 15:14:37.573695       1 roleRef.go:101]  "msg"="found a matched user/group 'system:masters' in request userInfo: [system:masters system:authenticated provisioning]"
I0324 15:14:37.573712       1 roleRef.go:101]  "msg"="found a matched user/group 'system:authenticated' in request userInfo: [system:masters system:authenticated provisioning]"
I0324 15:14:37.575711       1 context.go:234] context "msg"="Adding service account" "service account name"="" "service account namespace"=""
I0324 15:14:37.575834       1 context.go:278]  "msg"="updated image info" "images"={"containers":{"test":{"registry":"CORPORATE-REGISTRY","name":"heap-dump-service","path":"tobias.trabelsi/heap-dump-service","tag":"4d01f64e2eb82e1e6d9f6bf4816d8044fa148433"}}}
I0324 15:14:37.576871       1 imageVerify.go:83] EngineVerifyImages "msg"="processed image verification rules" "applied"=0 "kind"="Pod" "name"="test" "namespace"="test-tt" "policy"="check-image-signature" "successful"=true "time"="540.036µs"
I0324 15:14:37.576902       1 block.go:33] webhooks/resource/mutate "msg"="allowing admission request" "gvk"={"group":"","version":"v1","kind":"Pod"} "kind"="Pod" "name"="test" "namespace"="test-tt" "operation"="CREATE" "uid"="cd988e6c-cb86-45e6-8bae-bdd9d0dcab16" "user"={"username":"provisioning","groups":["system:masters","system:authenticated"]}
I0324 15:14:37.577633       1 admission.go:71] webhooks/resource/mutate "msg"="admission review request processed" "gvk"={"group":"","version":"v1","kind":"Pod"} "kind"="Pod" "name"="test" "namespace"="test-tt" "operation"="CREATE" "time"="50.266567ms" "uid"="cd988e6c-cb86-45e6-8bae-bdd9d0dcab16" "user"={"username":"provisioning","groups":["system:masters","system:authenticated"]}
I0324 15:14:37.596380       1 handlers.go:106] webhooks/resource/validate "msg"="received an admission request in validating webhook" "gvk"={"group":"","version":"v1","kind":"Pod"} "kind"="Pod" "name"="test" "namespace"="test-tt" "operation"="CREATE" "uid"="ac16963d-b4ef-4c14-9ba1-8e71e0dbeb49" "user"={"username":"provisioning","groups":["system:masters","system:authenticated"]}
I0324 15:14:37.596648       1 handlers.go:124] webhooks/resource/validate "msg"="processing policies for validate admission request" "generate"=0 "gvk"={"group":"","version":"v1","kind":"Pod"} "kind"="Pod" "mutate"=2 "name"="test" "namespace"="test-tt" "operation"="CREATE" "uid"="ac16963d-b4ef-4c14-9ba1-8e71e0dbeb49" "user"={"username":"provisioning","groups":["system:masters","system:authenticated"]} "validate"=1
I0324 15:14:37.596752       1 roleRef.go:101]  "msg"="found a matched user/group 'system:masters' in request userInfo: [system:masters system:authenticated provisioning]"
I0324 15:14:37.596813       1 roleRef.go:101]  "msg"="found a matched user/group 'system:authenticated' in request userInfo: [system:masters system:authenticated provisioning]"
I0324 15:14:37.596888       1 roleRef.go:101]  "msg"="found a matched user/group 'system:authenticated' in request userInfo: [system:masters system:authenticated provisioning]"
I0324 15:14:37.596933       1 roleRef.go:101]  "msg"="found a matched user/group 'system:authenticated' in request userInfo: [system:masters system:authenticated provisioning]"
I0324 15:14:37.598883       1 context.go:234] context "msg"="Adding service account" "service account name"="" "service account namespace"=""
I0324 15:14:37.599024       1 context.go:278]  "msg"="updated image info" "images"={"containers":{"test":{"registry":"CORPORATE-REGISTRY","name":"heap-dump-service","path":"tobias.trabelsi/heap-dump-service","tag":"4d01f64e2eb82e1e6d9f6bf4816d8044fa148433"}}}
I0324 15:14:37.599568       1 validation.go:45] EngineValidate "msg"="start validate policy processing" "kind"="Pod" "name"="test" "namespace"="test-tt" "policy"="check-image-signature" "startTime"="2023-03-24T15:14:37.599541118Z"
I0324 15:14:37.599632       1 validation.go:120] EngineValidate "msg"="processing validation rule" "applyRules"="All" "kind"="Pod" "matchCount"=0 "name"="test" "namespace"="test-tt" "policy"="check-image-signature"
I0324 15:14:37.600182       1 validation.go:146] EngineValidate "msg"="processing validation rule" "applyRules"="All" "kind"="Pod" "matchCount"=0 "name"="test" "namespace"="test-tt" "policy"="check-image-signature" "rule"="check-image-signature"
I0324 15:14:37.600264       1 imageVerifyValidate.go:66] EngineValidate "msg"="validating image" "image"="CORPORATE-REGISTRY/tobias.trabelsi/heap-dump-service:4d01f64e2eb82e1e6d9f6bf4816d8044fa148433" "kind"="Pod" "name"="test" "namespace"="test-tt" "policy"="check-image-signature" "rule"="check-image-signature"
I0324 15:14:37.600317       1 imageVerifyValidate.go:112] EngineValidate "msg"="missing image metadata in annotation" "key"="kyverno.io/verify-images" "kind"="Pod" "name"="test" "namespace"="test-tt" "policy"="check-image-signature" "rule"="check-image-signature"
I0324 15:14:37.600376       1 validation.go:177] EngineValidate "msg"="finished processing rule" "kind"="Pod" "name"="test" "namespace"="test-tt" "policy"="check-image-signature" "processingTime"="700.604µs" "rule"="check-image-signature"
I0324 15:14:37.600420       1 validation.go:48] EngineValidate "msg"="finished policy processing" "kind"="Pod" "name"="test" "namespace"="test-tt" "policy"="check-image-signature" "processingTime"="861.801µs" "validationRulesApplied"=1
I0324 15:14:37.600480       1 validation.go:118] webhooks/resource/validate "msg"="validation failed" "action"="Enforce" "failed rules"=["check-image-signature"] "gvk"={"group":"","version":"v1","kind":"Pod"} "kind"="Pod" "name"="test" "namespace"="test-tt" "operation"="CREATE" "policy"="check-image-signature" "resource"="test-tt/Pod/test" "uid"="ac16963d-b4ef-4c14-9ba1-8e71e0dbeb49" "user"={"username":"provisioning","groups":["system:masters","system:authenticated"]}
I0324 15:14:37.600531       1 block.go:29] webhooks/resource/validate "msg"="blocking admission request" "action"="validate" "gvk"={"group":"","version":"v1","kind":"Pod"} "kind"="Pod" "name"="test" "namespace"="test-tt" "operation"="CREATE" "policy"="check-image-signature" "resource"="test-tt/Pod/test" "uid"="ac16963d-b4ef-4c14-9ba1-8e71e0dbeb49" "user"={"username":"provisioning","groups":["system:masters","system:authenticated"]}
I0324 15:14:37.600590       1 validation.go:136] webhooks/resource/validate "msg"="admission request blocked" "action"="validate" "gvk"={"group":"","version":"v1","kind":"Pod"} "kind"="Pod" "name"="test" "namespace"="test-tt" "operation"="CREATE" "resource"="test-tt/Pod/test" "uid"="ac16963d-b4ef-4c14-9ba1-8e71e0dbeb49" "user"={"username":"provisioning","groups":["system:masters","system:authenticated"]}
I0324 15:14:37.600673       1 handlers.go:140] webhooks/resource/validate "msg"="admission request denied" "gvk"={"group":"","version":"v1","kind":"Pod"} "kind"="Pod" "name"="test" "namespace"="test-tt" "operation"="CREATE" "uid"="ac16963d-b4ef-4c14-9ba1-8e71e0dbeb49" "user"={"username":"provisioning","groups":["system:masters","system:authenticated"]}
I0324 15:14:37.600846       1 admission.go:71] webhooks/resource/validate "msg"="admission review request processed" "gvk"={"group":"","version":"v1","kind":"Pod"} "kind"="Pod" "name"="test" "namespace"="test-tt" "operation"="CREATE" "time"="4.580098ms" "uid"="ac16963d-b4ef-4c14-9ba1-8e71e0dbeb49" "user"={"username":"provisioning","groups":["system:masters","system:authenticated"]}

for me two lines checks out:

I0324 15:14:37.576871       1 imageVerify.go:83] EngineVerifyImages "msg"="processed image verification rules" "applied"=0 "kind"="Pod" "name"="test" "namespace"="test-tt" "policy"="check-image-signature" "successful"=true "time"="540.036µs"

followed by:

I0324 15:14:37.600317       1 imageVerifyValidate.go:112] EngineValidate "msg"="missing image metadata in annotation" "key"="kyverno.io/verify-images" "kind"="Pod" "name"="test" "namespace"="test-tt" "policy"="check-image-signature" "rule"="check-image-signature"

this feels like the role is evaluated twice, succeeds the first time and fails the second time. after reproducing this on a kind cluster i feel like i am hitting a bug in kyverno here or miss something too obvious 😅

Slack discussion

No response

Troubleshooting

• I have read and followed the documentation AND the troubleshooting guide.
• I have searched other issues in this repository and mine is not recorded.