Random registry push failures due to ActiveRecord::RecordInvalid (Validation failed: Name has already been taken)
This is a followup of #215715 (closed)
In %14.1 we delivered a fix, but in %14.3 we heard back on how this was not totally solved. In the previous month more feedback has been received and more details on how to reproduce this bug.
Summary
Podman gets error copying image to the remote destination: Error trying to reuse blob sha256:dbfdadd47341d8fef76248007931eade2b2039a376eb9e38861916be0cb06d40 at destination: unexpected http code: 422 (Unprocessable Entity)
Note this error only occurs on initial push attempt, all subsequent pushes are successful.
Steps to reproduce
Create Group/Project, ensure Container Registry is enabled. Authenticate podman to registry. Use podman to push image to the remote gitlab registry.
This issue can also be reproduced with other tools and not just podman. Another examples: gitlab-org/charts/gitlab#2590 (closed) and #340522
Example Project
NA
What is the current bug behavior?
Error is produced:
[root@localhost]# podman push localhost/hello/world:latest registry.example.com:4567/container-images/images/hello/world:latest
Getting image source signatures
Copying blob ebc8bce41e75 skipped: already exists
Copying blob 3115593a9788 skipped: already exists
Copying blob 877b494a9f30 skipped: already exists
Copying blob 27fe649c2f1d skipped: already exists
Copying blob 25ba9f7b8f48 skipped: already exists
Copying blob 662009dcc419 [--------------------------------------] 0.0b / 0.0b
Error: Error copying image to the remote destination: Error trying to reuse blob sha256:dbfdadd47341d8fef76248007931eade2b2039a376eb9e38861916be0cb06d40 at destination: unexpected http code: 422 (Unprocessable Entity), URL: https://registry.example.com:8881/jwt/auth?account=root&scope=repository%3Acontainer-images%2Fimages%2Fhello%2Fworld%3Apull%2Cpush&service=container_registryWhat is the expected correct behavior?
Push should complete with no errors and send metadata
Relevant logs and/or screenshots
Started GET "/jwt/auth?account=root&scope=repository%3Acontainer-images%2Fimages%2Fhello%2Fworld%3Apull%2Cpush&service=container_registry" for 172.30.30.10 at 2020-04-24 20:35:17 +0000
Started GET "/jwt/auth?account=root&scope=repository%3Acontainer-images%2Fimages%2Fhello%2Fworld%3Apull%2Cpush&service=container_registry" for 172.30.30.10 at 2020-04-24 20:35:17 +0000
Started GET "/jwt/auth?account=root&scope=repository%3Acontainer-images%2Fimages%2Fhello%2Fworld%3Apull%2Cpush&service=container_registry" for 172.30.30.10 at 2020-04-24 20:35:17 +0000
Started GET "/jwt/auth?account=root&scope=repository%3Acontainer-images%2Fimages%2Fhello%2Fworld%3Apull%2Cpush&service=container_registry" for 172.30.30.10 at 2020-04-24 20:35:17 +0000
Started GET "/jwt/auth?account=root&scope=repository%3Acontainer-images%2Fimages%2Fhello%2Fworld%3Apull%2Cpush&service=container_registry" for 172.30.30.10 at 2020-04-24 20:35:17 +0000
Started GET "/jwt/auth?account=root&scope=repository%3Acontainer-images%2Fimages%2Fhello%2Fworld%3Apull%2Cpush&service=container_registry" for 172.30.30.10 at 2020-04-24 20:35:17 +0000
Processing by JwtController#auth as HTML
Parameters: {"account"=>"root", "scope"=>"repository:container-images/images/hello/world:pull,push", "service"=>"container_registry"}
Processing by JwtController#auth as HTML
Processing by JwtController#auth as HTML
Parameters: {"account"=>"root", "scope"=>"repository:container-images/images/hello/world:pull,push", "service"=>"container_registry"}
Parameters: {"account"=>"root", "scope"=>"repository:container-images/images/hello/world:pull,push", "service"=>"container_registry"}
Processing by JwtController#auth as HTML
Processing by JwtController#auth as HTML
Processing by JwtController#auth as HTML
Parameters: {"account"=>"root", "scope"=>"repository:container-images/images/hello/world:pull,push", "service"=>"container_registry"}
Parameters: {"account"=>"root", "scope"=>"repository:container-images/images/hello/world:pull,push", "service"=>"container_registry"}
Parameters: {"account"=>"root", "scope"=>"repository:container-images/images/hello/world:pull,push", "service"=>"container_registry"}
Completed 200 OK in 185ms (Views: 0.3ms | ActiveRecord: 14.3ms | Elasticsearch: 0.0ms | Allocations: 15307)
Completed 422 Unprocessable Entity in 189ms (ActiveRecord: 20.8ms | Elasticsearch: 0.0ms | Allocations: 19141)
ActiveRecord::RecordInvalid (Validation failed: Name has already been taken):
app/models/container_repository.rb:94:in `tap'
app/models/container_repository.rb:94:in `create_from_path!'
lib/gitlab/metrics/instrumentation.rb:161:in `block in create_from_path!'Output of checks
NA
Results of GitLab environment info
Expand for output related to GitLab environment info
System information System: Current User: git Using RVM: no Ruby Version: 2.6.5p114 Gem Version: 2.7.10 Bundler Version:1.17.3 Rake Version: 12.3.3 Redis Version: 5.0.7 Git Version: 2.24.1 Sidekiq Version:5.2.7 Go Version: unknown GitLab information Version: 12.9.2 Revision: ac5568eb5d8 Directory: /opt/gitlab/embedded/service/gitlab-rails DB Adapter: PostgreSQL DB Version: 10.12 URL: https://puppet.dw.lab:8881 HTTP Clone URL: https://puppet.dw.lab:8881/some-group/some-project.git SSH Clone URL: ssh://git@puppet.dw.lab:8882/some-group/some-project.git Using LDAP: no Using Omniauth: yes Omniauth Providers: GitLab Shell Version: 12.0.0 Repository storage paths: - default: /var/opt/gitlab/git-data/repositories GitLab Shell path: /opt/gitlab/embedded/service/gitlab-shell Git: /opt/gitlab/embedded/bin/git
Results of GitLab application Check
Expand for output related to the GitLab application check
Checking GitLab subtasks ...
Checking GitLab Shell ...
GitLab Shell: ... GitLab Shell version >= 12.0.0 ? ... OK (12.0.0) Running /opt/gitlab/embedded/service/gitlab-shell/bin/check Internal API available: OK Redis available via internal API: OK gitlab-shell self-check successful
Checking GitLab Shell ... Finished
Checking Gitaly ...
Gitaly: ... default ... OK
Checking Gitaly ... Finished
Checking Sidekiq ...
Sidekiq: ... Running? ... yes Number of Sidekiq processes ... 1
Checking Sidekiq ... Finished
Checking Incoming Email ...
Incoming Email: ... Reply by email is disabled in config/gitlab.yml
Checking Incoming Email ... Finished
Checking LDAP ...
LDAP: ... LDAP is disabled in config/gitlab.yml
Checking LDAP ... Finished
Checking GitLab App ...
Git configured correctly? ... yes Database config exists? ... yes All migrations up? ... yes Database contains orphaned GroupMembers? ... no GitLab config exists? ... yes GitLab config up to date? ... yes Log directory writable? ... yes Tmp directory writable? ... yes Uploads directory exists? ... yes Uploads directory has correct permissions? ... yes Uploads directory tmp has correct permissions? ... skipped (no tmp uploads folder yet) Init script exists? ... skipped (omnibus-gitlab has no init script) Init script up-to-date? ... skipped (omnibus-gitlab has no init script) Projects have namespace: ... 2/1 ... yes Redis version >= 2.8.0? ... yes Ruby version >= 2.5.3 ? ... yes (2.6.5) Git version >= 2.22.0 ? ... yes (2.24.1) Git user has default SSH configuration? ... yes Active users: ... 1 Is authorized keys file accessible? ... yes
Checking GitLab App ... Finished
Checking GitLab subtasks ... Finished
Possible fixes
https://gitlab.com/gitlab-org/gitlab/-/blob/master/app/models/container_repository.rb#L96-103
Issue appears to be a race condition in caused by the jwt token service. Possible that multiple unsaved ContainerRepository objects are getting instantiated but not persisted yet. Then at some point are attempting to persist but failing validation. I have a fix that I will MR against this issue that catches the exception and will instead do a lookup of the persisted model.