Closed jhrozek closed 7 months ago
One such incident, from cloud watch:
@timestamp,message,count
2024-03-12 09:49:22.014,publishing of type: package,
2024-03-12 09:49:22.021,publishing of type: registry_package,
2024-03-12 09:49:22.021,webhook event not handled (webhook event not handled: event registry_package not handled),
2024-03-12 09:49:22.023,handling event for repository 770864070,
2024-03-12 09:49:22.820,"artifact version skipped, has no tags",
2024-03-12 09:49:23.174,publishing of type: pull_request_review,
2024-03-12 09:49:23.174,webhook event not handled (webhook event not handled: event pull_request_review not handled),
2024-03-12 09:49:23.287,publishing of type: pull_request_review_comment,
2024-03-12 09:49:23.287,webhook event not handled (webhook event not handled: event pull_request_review_comment not handled),
2024-03-12 09:49:23.866,publishing of type: registry_package,
2024-03-12 09:49:23.866,webhook event not handled (webhook event not handled: event registry_package not handled),
2024-03-12 09:49:23.895,publishing of type: package,
2024-03-12 09:49:23.897,handling event for repository 770864070,
2024-03-12 09:49:24.316,publishing of type: package,
2024-03-12 09:49:24.332,handling event for repository 770864070,
2024-03-12 09:49:24.498,"artifact version skipped, has no tags",
2024-03-12 09:49:24.706,publishing of type: registry_package,
2024-03-12 09:49:24.706,webhook event not handled (webhook event not handled: event registry_package not handled),
2024-03-12 09:49:24.860,Publishing messages,
2024-03-12 09:49:24.905,event ready to be executed,
2024-03-12 09:49:24.906,Handled message,
2024-03-12 09:49:24.906,,
2024-03-12 09:49:25.170,artifact version matched,
2024-03-12 09:49:25.170,skipping artifact version,
2024-03-12 09:49:25.170,skipping artifact version,
2024-03-12 09:49:25.273,verifying container artifact,
2024-03-12 09:49:25.517,listing repositories,
2024-03-12 09:49:25.525,number of sigstore bundles we managed to construct,0
2024-03-12 09:49:25.525,failed to find or verify signature information,
2024-03-12 09:49:25.526,ingestion result,
2024-03-12 09:49:25.527,result - evaluation,
2024-03-12 09:49:25.527,result - action,
2024-03-12 09:49:25.527,result - action,
2024-03-12 09:49:25.545,lock lease updated,
2024-03-12 09:49:25.558,Using cached result for github/group/0820ee4d-0e88-4d78-8aeb-1d63b397b2b4/artifact_signature,
2024-03-12 09:49:25.559,result - evaluation,
2024-03-12 09:49:25.559,result - action,
2024-03-12 09:49:25.559,result - action,
2024-03-12 09:49:25.594,listing repositories for the user,
@jhrozek and I looked into this. And it seems that the issue that the ingestcache is not able to uniquely identify a tag due to it not being part of the marshalled entity nor the parameters. So it re-uses the cache for different tags. This is not ideal. This is a little less problematic since we only instantiate the cache for a single execution of profiles. So, another event will have a fresh cache. But we should still figure out how to fix it.
Full minder logs from another failure:
{"level":"debug","Timestamp":1710250796124378753,"message":"publishing of type: registry_package"}
{"level":"debug","Timestamp":1710250796124399842,"message":"webhook event not handled (webhook event not handled: event registry_package not handled)"} {"level":"debug","Timestamp":1710250796286591440,"message":"publishing of type: package"}
{"level":"debug","Timestamp":1710250796289192184,"message":"handling event for repository 770983033"} {"level":"debug","Timestamp":1710250796780726841,"message":"publishing of type: package"}
{"level":"debug","Timestamp":1710250796782407369,"message":"handling event for repository 770983033"} {"level":"debug","Timestamp":1710250796874504003,"message":"artifact version skipped, has no tags"}
{"level":"debug","Timestamp":1710250796999377686,"message":"publishing of type: registry_package"}
{"level":"debug","Timestamp":1710250796999396723,"message":"webhook event not handled (webhook event not handled: event registry_package not handled)"}
{"level":"debug","Timestamp":1710250797297215804,"message":"artifact version skipped, has no tags"}
{"level":"debug","Timestamp":1710250797306347701,"message":"publishing of type: registry_package"}
{"level":"debug","Timestamp":1710250797306367789,"message":"webhook event not handled (webhook event not handled: event registry_package not handled)"} {"level":"debug","Timestamp":1710250797311225229,"message":"publishing of type: package"}
{"level":"debug","Timestamp":1710250797313153582,"message":"handling event for repository 770983033"}
{"level":"info","component":"watermill","message_uuid":"102d5527-57e6-434d-8c29-60c53613d590","topic":"execute.entity.event","handler":"github.com/stacklok/minder/internal/controlplane.(*Server).StartHTTPServer.(*Server).HandleGitHubWebHook.func7","Timestamp":1710250798063921654,"message":"Publishing messages"}
{"level":"info","event":"102d5527-57e6-434d-8c29-60c53613d590","entity":"artifact","repository_id":"a1b70b81-0eb6-4a90-8666-994070c847dd","artifact_id":"8b5efded-55f8-4f40-a5a8-0c9a3ea25dcb","execution_id":"4fa05f6d-a041-4765-9e1f-10d498bd075c","Timestamp":1710250798622757523,"message":"event ready to be executed"} {"level":"info","component":"watermill","message_uuid":"102d5527-57e6-434d-8c29-60c53613d590","topic":"execute.entity.event","handler":"github.com/stacklok/minder/internal/engine.(*Executor).HandleEntityEvent-fm-execute.entity.event","Timestamp":1710250798622888299,"message":"Handled message"}
{"level":"info","project":"9fdae8af-1668-48c9-a195-9195901a49c4","provider":"github","artifact":"8b5efded-55f8-4f40-a5a8-0c9a3ea25dcb","telemetry":"true","Timestamp":1710250798622902442}
{"level":"debug","name":"sha256:f854f0c0b7dc9676d2056c4e6acd22e2b68f8c4fe021100f0c1a277b825f7770","tags":["static"],"Timestamp":1710250798843864784,"message":"artifact version matched"}
{"level":"debug","name":"sha256:9da0d491fc3059971e573249bf1ebe3139a68ad32eb96e43aea8ee67eb94c125","tags":[],"reason":"artifact has no tags","Timestamp":1710250798843885610,"message":"skipping artifact version"} {"level":"debug","name":"sha256:2bdbb5dc1c8829210bd78fbe54ee39fdbec99e839a0a87599302ea3c53133141","tags":[],"reason":"artifact has no tags","Timestamp":1710250798843887902,"message":"skipping artifact version"}
{"level":"info","imageRef":"ghcr.io/stacklok-minder-tests/smoke-test-go-6971@sha256:f854f0c0b7dc9676d2056c4e6acd22e2b68f8c4fe021100f0c1a277b825f7770","Timestamp":1710250798926070908,"message":"verifying container artifact"} {"level":"info","count":0,"Timestamp":1710250799230268636,"message":"number of sigstore bundles we managed to construct"}
{"level":"debug","name":"/stacklok-minder-tests/smoke-test-go-6971@sha256:f854f0c0b7dc9676d2056c4e6acd22e2b68f8c4fe021100f0c1a277b825f7770","Timestamp":1710250799230287058,"message":"failed to find or verify signature information"} {"level":"debug","result":[{"Verification":{"is_signed":false,"is_verified":false,"repository":"","branch":"","signer_identity":"","runner_environment":"","cert_issuer":""}}],"Timestamp":1710250799230300086,"message":"ingestion result"}
{"level":"debug","profile":"signed-artifact-simple","ruleType":"artifact_signature","ruleName":"artifact_signature","eval_status":"failure","projectId":"9fdae8af-1668-48c9-a195-9195901a49c4","repositoryId":"a1b70b81-0eb6-4a90-8666-994070c847dd","artifactId":"8b5efded-55f8-4f40-a5a8-0c9a3ea25dcb","exception.message":"evaluation failure: denied","Timestamp":1710250799232697408,"message":"result - evaluation"}
{"level":"info","action":"remediate","action_status":"skipped","Timestamp":1710250799233544946,"message":"result - action"} {"level":"info","action":"alert","action_status":"skipped","Timestamp":1710250799234204220,"message":"result - action"}
{"level":"info","entity_type":"artifact","execution_id":"4fa05f6d-a041-4765-9e1f-10d498bd075c","repo_id":"a1b70b81-0eb6-4a90-8666-994070c847dd","artifact_id":"8b5efded-55f8-4f40-a5a8-0c9a3ea25dcb","Timestamp":1710250799262565460,"message":"lock lease updated"} {"level":"debug","Timestamp":1710250799266650470,"message":"Using cached result for github/group/9fdae8af-1668-48c9-a195-9195901a49c4/artifact_signature"}
{"level":"debug","profile":"signed-artifact-hardened","ruleType":"artifact_signature","ruleName":"artifact_signature","eval_status":"failure","projectId":"9fdae8af-1668-48c9-a195-9195901a49c4","repositoryId":"a1b70b81-0eb6-4a90-8666-994070c847dd","artifactId":"8b5efded-55f8-4f40-a5a8-0c9a3ea25dcb","exception.message":"evaluation failure: denied","Timestamp":1710250799267797138,"message":"result - evaluation"}
{"level":"info","action":"remediate","action_status":"skipped","Timestamp":1710250799267808944,"message":"result - action"} {"level":"info","action":"alert","action_status":"skipped","Timestamp":1710250799267811218,"message":"result - action"}
{"level":"info","entity_type":"artifact","execution_id":"4fa05f6d-a041-4765-9e1f-10d498bd075c","repo_id":"a1b70b81-0eb6-4a90-8666-994070c847dd","artifact_id":"8b5efded-55f8-4f40-a5a8-0c9a3ea25dcb","Timestamp":1710250799282410699,"message":"lock lease updated"} {"level":"info","component":"watermill","message_uuid":"052fc71c-e076-11ee-93f0-d6be0c9d27f9","topic":"flush.entity.event","handler":"github.com/stacklok/minder/internal/engine.(*Executor).releaseLockAndFlush","Timestamp":1710250799284491786,"message":"Publishing messages"}
{"level":"info","project":"9fdae8af-1668-48c9-a195-9195901a49c4","provider":"github","artifact":"8b5efded-55f8-4f40-a5a8-0c9a3ea25dcb","rules":[{"ruletype":{"name":"artifact_signature","id":"87a57822-9f1b-4b38-bb18-0ce7000dfaf8"},"profile":{"name":"signed-artifact-simple","id":"30bfc7f0-465a-4789-bada-9d426a1d3647"},"eval_result":"failure","actions":{"alert":{"state":"off","result":"skipped"},"remediate":{"state":"off","result":"skipped"}}},{"ruletype":{"name":"artifact_signature","id":"87a57822-9f1b-4b38-bb18-0ce7000dfaf8"},"profile":{"name":"signed-artifact-hardened","id":"74348523-ac1f-4d02-89cd-bb5ceff5d76f"},"eval_result":"failure","actions":{"alert":{"state":"off","result":"skipped"},"remediate":{"state":"off","r
esult":"skipped"}}}],"telemetry":"true","Timestamp":1710250799287026237} {"level":"debug","Timestamp":1710250799302689014,"message":"publishing of type: workflow_job"}
{"level":"debug","Timestamp":1710250799302708948,"message":"webhook event not handled (webhook event not handled: event workflow_job not handled)"} {"level":"debug","Timestamp":1710250799556182384,"message":"publishing of type: check_run"}
{"level":"debug","Timestamp":1710250799556203231,"message":"webhook event not handled (webhook event not handled: event check_run not handled)"} {"level":"info","event":"052fc71c-e076-11ee-93f0-d6be0c9d27f9","entity":"artifact","repository_id":"a1b70b81-0eb6-4a90-8666-994070c847dd","Timestamp":1710250799573393771,"message":"flushing event"}
{"level":"info","event":"052fc71c-e076-11ee-93f0-d6be0c9d27f9","entity":"artifact","repository_id":"a1b70b81-0eb6-4a90-8666-994070c847dd","Timestamp":1710250799574725837,"message":"no flushing needed"} {"level":"info","component":"watermill","message_uuid":"052fc71c-e076-11ee-93f0-d6be0c9d27f9","topic":"flush.entity.event","handler":"github.com/stacklok/minder/internal/eea.(*EEA).FlushMessageHandler-fm-flush.entity.event","Timestamp":1710250799574745701,"message":"Handled message"}
{"level":"debug","Timestamp":1710250799604848994,"message":"publishing of type: workflow_run"}
{"level":"debug","Timestamp":1710250799604870795,"message":"webhook event not handled (webhook event not handled: event workflow_run not handled)"}
{"level":"debug","Timestamp":1710250799625407825,"message":"publishing of type: check_suite"}
{"level":"debug","Timestamp":1710250799625425616,"message":"webhook event not handled (webhook event not handled: event check_suite not handled)"}
{"level":"info","Resource":{"service":"minder.v1.EvalResultsService","method":"ListEvaluationResults"},"login_sha":"2c8e25c1e61cb56311c92c272f78c609590624b1064c1f8735d8bf1e14831715","telemetry":"true","Attributes":{"http.code":"OK","http.content-type":["application/grpc"],"http.duration":"14.261911ms","http.forwarded":["46.6.36.217, 10.0.32.100"],"http.user_agen
t":["grpc-go/1.62.1"]},"Timestamp":1710250804678233259}
{"level":"debug","Timestamp":1710250805457303124,"message":"publishing of type: workflow_run"}
{"level":"debug","Timestamp":1710250805457322557,"message":"webhook event not handled (webhook event not handled: event workflow_run not handled)"}
{"level":"debug","Timestamp":1710250805539752244,"message":"publishing of type: workflow_job"}
{"level":"debug","Timestamp":1710250805539772598,"message":"webhook event not handled (webhook event not handled: event workflow_job not handled)"}
{"level":"debug","Timestamp":1710250805569390590,"message":"publishing of type: check_suite"}
{"level":"debug","Timestamp":1710250805569411070,"message":"webhook event not handled (webhook event not handled: event check_suite not handled)"}
{"level":"debug","Timestamp":1710250805721514665,"message":"publishing of type: check_run"}
{"level":"debug","Timestamp":1710250805721535581,"message":"webhook event not handled (webhook event not handled: event check_run not handled)"}
{"level":"info","Resource":{"service":"minder.v1.ArtifactService","method":"ListArtifacts"},"project":"9fdae8af-1668-48c9-a195-9195901a49c4","provider":"github","login_sha":"f4236defc46217b7d82316465b7b6eec2a5bdc8b8b2ba90339c2bb729dc7f2bb","telemetry":"true","Attributes":{"http.code":"OK","http.content-type":["application/grpc"],"http.duration":"10.693799ms","ht
tp.forwarded":["20.42.15.84"],"http.user_agent":["minder-cli/0.0.34 (linux) amd64 (go1.21.7) grpc-go/1.62.0"]},"Timestamp":1710250806651750664}
{"level":"info","Resource":{"service":"minder.v1.ProfileService","method":"GetProfileStatusByName"},"project":"9fdae8af-1668-48c9-a195-9195901a49c4","provider":"github","login_sha":"f4236defc46217b7d82316465b7b6eec2a5bdc8b8b2ba90339c2bb729dc7f2bb","profile":{"name":"signed-artifact-simple","id":"30bfc7f0-465a-4789-bada-9d426a1d3647"},"telemetry":"true","Attribut
es":{"http.code":"OK","http.content-type":["application/grpc"],"http.duration":"16.061709ms","http.forwarded":["20.42.15.84"],"http.user_agent":["minder-cli/0.0.34 (linux) amd64 (go1.21.7) grpc-go/1.62.0"]},"Timestamp":1710250806752935154}
{"level":"info","Resource":{"service":"minder.v1.ProfileService","method":"GetProfileStatusByName"},"project":"9fdae8af-1668-48c9-a195-9195901a49c4","provider":"github","login_sha":"f4236defc46217b7d82316465b7b6eec2a5bdc8b8b2ba90339c2bb729dc7f2bb","profile":{"name":"signed-artifact-simple","id":"30bfc7f0-465a-4789-bada-9d426a1d3647"},"telemetry":"true","Attribut
es":{"http.code":"OK","http.content-type":["application/grpc"],"http.duration":"20.836884ms","http.forwarded":["20.42.15.84"],"http.user_agent":["minder-cli/0.0.34 (linux) amd64 (go1.21.7) grpc-go/1.62.0"]},"Timestamp":1710250806846072039}
{"level":"info","Resource":{"service":"minder.v1.ProfileService","method":"GetProfileStatusByName"},"project":"9fdae8af-1668-48c9-a195-9195901a49c4","provider":"github","login_sha":"f4236defc46217b7d82316465b7b6eec2a5bdc8b8b2ba90339c2bb729dc7f2bb","profile":{"name":"signed-artifact-simple","id":"30bfc7f0-465a-4789-bada-9d426a1d3647"},"telemetry":"true","Attribut
es":{"http.code":"OK","http.content-type":["application/grpc"],"http.duration":"18.040094ms","http.forwarded":["20.42.15.84"],"http.user_agent":["minder-cli/0.0.34 (linux) amd64 (go1.21.7) grpc-go/1.62.0"]},"Timestamp":1710250807936502286}
{"level":"info","Resource":{"service":"minder.v1.ProfileService","method":"GetProfileStatusByName"},"project":"9fdae8af-1668-48c9-a195-9195901a49c4","provider":"github","login_sha":"f4236defc46217b7d82316465b7b6eec2a5bdc8b8b2ba90339c2bb729dc7f2bb","profile":{"name":"signed-artifact-simple","id":"30bfc7f0-465a-4789-bada-9d426a1d3647"},"telemetry":"true","Attribut
es":{"http.code":"OK","http.content-type":["application/grpc"],"http.duration":"60.951582ms","http.forwarded":["20.42.15.84"],"http.user_agent":["minder-cli/0.0.34 (linux) amd64 (go1.21.7) grpc-go/1.62.0"]},"Timestamp":1710250808071815783}
{"level":"info","Resource":{"service":"minder.v1.ProfileService","method":"GetProfileStatusByName"},"project":"9fdae8af-1668-48c9-a195-9195901a49c4","provider":"github","login_sha":"f4236defc46217b7d82316465b7b6eec2a5bdc8b8b2ba90339c2bb729dc7f2bb","profile":{"name":"signed-artifact-simple","id":"30bfc7f0-465a-4789-bada-9d426a1d3647"},"telemetry":"true","Attribut
es":{"http.code":"OK","http.content-type":["application/grpc"],"http.duration":"14.275327ms","http.forwarded":["20.42.15.84"],"http.user_agent":["minder-cli/0.0.34 (linux) amd64 (go1.21.7) grpc-go/1.62.0"]},"Timestamp":1710250809159190413}
For comparison, a succeeding run:
{"level":"debug","Timestamp":1710251569963695187,"message":"handling event for repository 770989595"}
{"level":"debug","Timestamp":1710251570582822739,"message":"artifact version skipped, has no tags"} {"level":"debug","Timestamp":1710251570938940052,"message":"publishing of type: package"}
{"level":"debug","Timestamp":1710251570940261665,"message":"handling event for repository 770989595"} {"level":"debug","Timestamp":1710251571259713802,"message":"publishing of type: registry_package"}
{"level":"debug","Timestamp":1710251571259733467,"message":"webhook event not handled (webhook event not handled: event registry_package not handled)"} {"level":"debug","Timestamp":1710251571410669216,"message":"publishing of type: package"}
{"level":"debug","Timestamp":1710251571412067203,"message":"publishing of type: registry_package"} {"level":"debug","Timestamp":1710251571412082376,"message":"webhook event not handled (webhook event not handled: event registry_package not handled)"}
{"level":"debug","Timestamp":1710251571412326815,"message":"handling event for repository 770989595"} {"level":"debug","Timestamp":1710251571548969923,"message":"artifact version skipped, has no tags"}
{"level":"info","component":"watermill","message_uuid":"f63004e3-bdf1-4179-acaa-58918b592085","topic":"execute.entity.event","handler":"github.com/stacklok/minder/internal/controlplane.(*Server).StartHTTPServer.(*Server).HandleGitHubWebHook.func7","Timestamp":1710251572055821622,"message":"Publishing messages"} {"level":"info","event":"f63004e3-bdf1-4179-acaa-58918b592085","entity":"artifact","repository_id":"3509bb5f-c7c4-436f-ac75-e417540b1783","artifact_id":"f0584c0b-e07e-45b4-b2bb-f3bbdffe5c72","execution_id":"8df3e2a7-5209-4f39-b96f-9927fadbe7dd","Timestamp":1710251572363497576,"message":"event ready to be executed"}
{"level":"info","component":"watermill","message_uuid":"f63004e3-bdf1-4179-acaa-58918b592085","topic":"execute.entity.event","handler":"github.com/stacklok/minder/internal/engine.(*Executor).HandleEntityEvent-fm-execute.entity.event","Timestamp":1710251572363758390,"message":"Handled message"} {"level":"info","project":"9fdae8af-1668-48c9-a195-9195901a49c4","provider":"github","artifact":"f0584c0b-e07e-45b4-b2bb-f3bbdffe5c72","telemetry":"true","Timestamp":1710251572363770183}
{"level":"info","event":"f63004e3-bdf1-4179-acaa-58918b592085","entity":"artifact","repository_id":"3509bb5f-c7c4-436f-ac75-e417540b1783","artifact_id":"f0584c0b-e07e-45b4-b2bb-f3bbdffe5c72","Timestamp":1710251572396343565,"message":"event not ready to be executed"} {"level":"debug","name":"sha256:37345ae18f4979b83081ff623d7ee316d985a8809145f955b233e5b663544cf3","tags":["static"],"Timestamp":1710251572622274579,"message":"artifact version matched"}
{"level":"debug","name":"sha256:d071a8d807fe472dcb2283d08e8f348ae6c6d2c1fabe208e1a4cd8673dee4bf0","tags":[],"reason":"artifact has no tags","Timestamp":1710251572622294078,"message":"skipping artifact version"}
{"level":"debug","name":"sha256:2bdbb5dc1c8829210bd78fbe54ee39fdbec99e839a0a87599302ea3c53133141","tags":[],"reason":"artifact has no tags","Timestamp":1710251572622296410,"message":"skipping artifact version"}
{"level":"info","imageRef":"ghcr.io/stacklok-minder-tests/smoke-test-go-1356@sha256:37345ae18f4979b83081ff623d7ee316d985a8809145f955b233e5b663544cf3","Timestamp":1710251572671145382,"message":"verifying container artifact"}
{"level":"info","count":1,"Timestamp":1710251573012889705,"message":"number of sigstore bundles we managed to construct"} {"level":"debug","result":[{"Verification":{"is_signed":true,"is_verified":true,"repository":"https://github.com/stacklok-minder-tests/smoke-test-go-1356","branch":"main","signer_identity":"build-image-signed-cosign-static.yml","runner_environment":"github-hosted","cert_issuer":"https://token.actions.githubusercontent.com"}}],"Timestamp":1710251573017878865,"mes
sage":"ingestion result"} {"level":"debug","profile":"signed-artifact-simple","ruleType":"artifact_signature","ruleName":"artifact_signature","eval_status":"success","projectId":"9fdae8af-1668-48c9-a195-9195901a49c4","repositoryId":"3509bb5f-c7c4-436f-ac75-e417540b1783","artifactId":"f0584c0b-e07e-45b4-b2bb-f3bbdffe5c72","Timestamp":1710251573018873537,"message":"result - evaluation"}
{"level":"info","action":"remediate","action_status":"skipped","Timestamp":1710251573018890703,"message":"result - action"}
{"level":"info","action":"alert","action_status":"skipped","Timestamp":1710251573018892677,"message":"result - action"}
{"level":"info","entity_type":"artifact","execution_id":"8df3e2a7-5209-4f39-b96f-9927fadbe7dd","repo_id":"3509bb5f-c7c4-436f-ac75-e417540b1783","artifact_id":"f0584c0b-e07e-45b4-b2bb-f3bbdffe5c72","Timestamp":1710251573065275784,"message":"lock lease updated"}
{"level":"debug","Timestamp":1710251573069806523,"message":"Using cached result for github/group/9fdae8af-1668-48c9-a195-9195901a49c4/artifact_signature"}
{"level":"debug","profile":"signed-artifact-hardened","ruleType":"artifact_signature","ruleName":"artifact_signature","eval_status":"failure","projectId":"9fdae8af-1668-48c9-a195-9195901a49c4","repositoryId":"3509bb5f-c7c4-436f-ac75-e417540b1783","artifactId":"f0584c0b-e07e-45b4-b2bb-f3bbdffe5c72","exception.message":"evaluation failure: denied","Timestamp":1710
251573071698387,"message":"result - evaluation"}
{"level":"info","action":"remediate","action_status":"skipped","Timestamp":1710251573071713671,"message":"result - action"}
{"level":"info","action":"alert","action_status":"skipped","Timestamp":1710251573071716015,"message":"result - action"}
{"level":"info","entity_type":"artifact","execution_id":"8df3e2a7-5209-4f39-b96f-9927fadbe7dd","repo_id":"3509bb5f-c7c4-436f-ac75-e417540b1783","artifact_id":"f0584c0b-e07e-45b4-b2bb-f3bbdffe5c72","Timestamp":1710251573088901322,"message":"lock lease updated"}
{"level":"info","component":"watermill","message_uuid":"d269c0bb-e077-11ee-93f0-d6be0c9d27f9","topic":"flush.entity.event","handler":"github.com/stacklok/minder/internal/engine.(*Executor).releaseLockAndFlush","Timestamp":1710251573094105892,"message":"Publishing messages"}
{"level":"info","project":"9fdae8af-1668-48c9-a195-9195901a49c4","provider":"github","artifact":"f0584c0b-e07e-45b4-b2bb-f3bbdffe5c72","rules":[{"ruletype":{"name":"artifact_signature","id":"786f2133-b603-4875-af0c-d62a10ec7b4e"},"profile":{"name":"signed-artifact-simple","id":"fd4d97f6-6f4a-4503-a11e-5620dc30e2b8"},"eval_result":"success","actions":{"alert":{"s
tate":"off","result":"skipped"},"remediate":{"state":"off","result":"skipped"}}},{"ruletype":{"name":"artifact_signature","id":"786f2133-b603-4875-af0c-d62a10ec7b4e"},"profile":{"name":"signed-artifact-hardened","id":"8ff2e500-0e08-432f-bf7e-0bbc8452d27a"},"eval_result":"failure","actions":{"alert":{"state":"off","result":"skipped"},"remediate":{"state":"off","r
esult":"skipped"}}}],"telemetry":"true","Timestamp":1710251573098635455}
{"level":"info","event":"d269c0bb-e077-11ee-93f0-d6be0c9d27f9","entity":"artifact","repository_id":"3509bb5f-c7c4-436f-ac75-e417540b1783","Timestamp":1710251573695109648,"message":"flushing event"}
{"level":"info","event":"d269c0bb-e077-11ee-93f0-d6be0c9d27f9","entity":"artifact","repository_id":"3509bb5f-c7c4-436f-ac75-e417540b1783","Timestamp":1710251573697941665,"message":"re-publishing event because of flush"}
{"level":"info","component":"watermill","handler":"github.com/stacklok/minder/internal/engine/entities.(*EntityInfoWrapper).Publish","message_uuid":"d2c5e908-e077-11ee-93f0-d6be0c9d27f9","topic":"execute.entity.event","Timestamp":1710251573698054251,"message":"Publishing messages"}
{"level":"info","component":"watermill","topic":"flush.entity.event","handler":"github.com/stacklok/minder/internal/eea.(*EEA).FlushMessageHandler-fm-flush.entity.event","message_uuid":"d269c0bb-e077-11ee-93f0-d6be0c9d27f9","Timestamp":1710251573700953424,"message":"Handled message"}
{"level":"info","event":"d269c0bb-e077-11ee-93f0-d6be0c9d27f9","entity":"artifact","repository_id":"3509bb5f-c7c4-436f-ac75-e417540b1783","Timestamp":1710251573722785543,"message":"flushing event"}
{"level":"info","event":"d269c0bb-e077-11ee-93f0-d6be0c9d27f9","entity":"artifact","repository_id":"3509bb5f-c7c4-436f-ac75-e417540b1783","Timestamp":1710251573724379829,"message":"no flushing needed"}
{"level":"info","component":"watermill","message_uuid":"d269c0bb-e077-11ee-93f0-d6be0c9d27f9","topic":"flush.entity.event","handler":"github.com/stacklok/minder/internal/eea.(*EEA).FlushMessageHandler-fm-flush.entity.event","Timestamp":1710251573724395572,"message":"Handled message"}
{"level":"info","event":"d2c5e908-e077-11ee-93f0-d6be0c9d27f9","entity":"artifact","repository_id":"3509bb5f-c7c4-436f-ac75-e417540b1783","artifact_id":"f0584c0b-e07e-45b4-b2bb-f3bbdffe5c72","execution_id":"c3483e48-528f-4118-bd43-faa01fe1b250","Timestamp":1710251574507091011,"message":"event ready to be executed"}
{"level":"info","component":"watermill","topic":"execute.entity.event","handler":"github.com/stacklok/minder/internal/engine.(*Executor).HandleEntityEvent-fm-execute.entity.event","message_uuid":"d2c5e908-e077-11ee-93f0-d6be0c9d27f9","Timestamp":1710251574507266235,"message":"Handled message"}
{"level":"info","project":"9fdae8af-1668-48c9-a195-9195901a49c4","provider":"github","artifact":"f0584c0b-e07e-45b4-b2bb-f3bbdffe5c72","telemetry":"true","Timestamp":1710251574507313744}
{"level":"info","event":"d2c5e908-e077-11ee-93f0-d6be0c9d27f9","entity":"artifact","repository_id":"3509bb5f-c7c4-436f-ac75-e417540b1783","artifact_id":"f0584c0b-e07e-45b4-b2bb-f3bbdffe5c72","Timestamp":1710251574516072127,"message":"event not ready to be executed"}
{"level":"debug","name":"sha256:49f1c8e856f73e1d80e3210f6a8cc8f1aeae62d52a62f5dcef1d1e924013c8b7","tags":["sha256-37345ae18f4979b83081ff623d7ee316d985a8809145f955b233e5b663544cf3.sig"],"reason":"artifact is a signature","Timestamp":1710251574722247278,"message":"skipping artifact version"}
{"level":"debug","name":"sha256:37345ae18f4979b83081ff623d7ee316d985a8809145f955b233e5b663544cf3","tags":["static"],"Timestamp":1710251574722264172,"message":"artifact version matched"}
{"level":"debug","name":"sha256:d071a8d807fe472dcb2283d08e8f348ae6c6d2c1fabe208e1a4cd8673dee4bf0","tags":[],"reason":"artifact has no tags","Timestamp":1710251574722266729,"message":"skipping artifact version"}
{"level":"debug","name":"sha256:2bdbb5dc1c8829210bd78fbe54ee39fdbec99e839a0a87599302ea3c53133141","tags":[],"reason":"artifact has no tags","Timestamp":1710251574722268188,"message":"skipping artifact version"}
{"level":"info","imageRef":"ghcr.io/stacklok-minder-tests/smoke-test-go-1356@sha256:37345ae18f4979b83081ff623d7ee316d985a8809145f955b233e5b663544cf3","Timestamp":1710251574772553877,"message":"verifying container artifact"}
{"level":"info","count":1,"Timestamp":1710251575226910809,"message":"number of sigstore bundles we managed to construct"}
{"level":"debug","result":[{"Verification":{"is_signed":true,"is_verified":true,"repository":"https://github.com/stacklok-minder-tests/smoke-test-go-1356","branch":"main","signer_identity":"build-image-signed-cosign-static.yml","runner_environment":"github-hosted","cert_issuer":"https://token.actions.githubusercontent.com"}}],"Timestamp":1710251575231803056,"mes
sage":"ingestion result"}
{"level":"debug","profile":"signed-artifact-simple","ruleType":"artifact_signature","ruleName":"artifact_signature","eval_status":"success","projectId":"9fdae8af-1668-48c9-a195-9195901a49c4","repositoryId":"3509bb5f-c7c4-436f-ac75-e417540b1783","artifactId":"f0584c0b-e07e-45b4-b2bb-f3bbdffe5c72","Timestamp":1710251575232905899,"message":"result - evaluation"}
{"level":"info","action":"remediate","action_status":"skipped","Timestamp":1710251575232921397,"message":"result - action"}
{"level":"info","action":"alert","action_status":"skipped","Timestamp":1710251575232923626,"message":"result - action"}
It seems like in the first case we only see 1 run of the ingestor and it's not finding any signatures.
This is no longer a problem since 902468781acfd507e96c52a62fd662576ca24b1f
Describe the issue
The artifact ingestor also checks the sigstore signatures and lists all artifact versions matching the artifact which might take a long time. At the same time, signatures are often pushed to the container registry right after the unsigned package is, which is leading to races:
package
webhook eventpackage
webhook events while the first one is still running and caches their receptionBecause the cache is for a single eval entity event I think the interplay between the ingester cache and the event cache is important in the sense that the bug only manifests when we lump multiple events together.
To Reproduce
This seems to be a race, so not 100%
What version are you using?
No response