Bug 1349980 - Unable to sync Docker Containers to Satellite if repository already exists
Summary: Unable to sync Docker Containers to Satellite if repository already exists
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Satellite
Classification: Red Hat
Component: Repositories
Version: 6.2.0
Hardware: x86_64
OS: Linux
high
medium
Target Milestone: Unspecified
Assignee: David Davis
QA Contact: jcallaha
URL: http://projects.theforeman.org/issues...
Whiteboard:
: 1363854 (view as bug list)
Depends On:
Blocks: rhci-common-installer
TreeView+ depends on / blocked
 
Reported: 2016-06-24 17:49 UTC by Dylan Murray
Modified: 2019-09-25 21:19 UTC (History)
14 users (show)

Fixed In Version: rubygem-katello-3.0.0.70-1
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2016-08-16 11:19:58 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)
foreman-debug tarball (770.55 KB, application/x-xz)
2016-06-24 18:22 UTC, Dylan Murray
no flags Details


Links
System ID Private Priority Status Summary Last Updated
Foreman Issue Tracker 15971 0 High Closed Unable to sync Docker Containers to Satellite if repository already exists 2020-09-15 20:23:20 UTC

Description Dylan Murray 2016-06-24 17:49:43 UTC
Description of problem:


Version-Release number of selected component (if applicable):


How reproducible:
60%

Steps to Reproduce:
1. Create a new product with associated repositories from Docker Registry
2. Sync containers successfully
3. Try to resync repositories via API

Actual results:

Actions::Katello::Repository::IndexContent
 
Input:
 
{"id"=>59, "contents_changed"=>true, "current_user_id"=>3, "locale"=>"en"}
 
Output:
 
{}
 
Exception:
 
NoMethodError: undefined method `[]' for nil:NilClass
 
Backtrace:
 
/git/katello/app/models/katello/glue/pulp/repo.rb:466:in `create_docker_tag'
/git/katello/app/models/katello/glue/pulp/repo.rb:447:in `block in index_db_docker_manifests'
/git/katello/app/models/katello/glue/pulp/repo.rb:444:in `each'
/git/katello/app/models/katello/glue/pulp/repo.rb:444:in `index_db_docker_manifests'
/git/katello/app/models/katello/glue/pulp/repo.rb:849:in `index_content'
/git/katello/app/lib/actions/katello/repository/index_content.rb:16:in `run'
/git/.rvm/gems/ruby-2.2.4/gems/dynflow-0.8.11/lib/dynflow/action.rb:506:in `block (3 levels) in execute_run'
/git/.rvm/gems/ruby-2.2.4/gems/dynflow-0.8.11/lib/dynflow/middleware/stack.rb:26:in `call'
/git/.rvm/gems/ruby-2.2.4/gems/dynflow-0.8.11/lib/dynflow/middleware/stack.rb:26:in `pass'
/git/.rvm/gems/ruby-2.2.4/gems/dynflow-0.8.11/lib/dynflow/middleware.rb:17:in `pass'
/git/katello/app/lib/actions/middleware/execute_if_contents_changed.rb:5:in `run'
/git/.rvm/gems/ruby-2.2.4/gems/dynflow-0.8.11/lib/dynflow/middleware/stack.rb:22:in `call'
/git/.rvm/gems/ruby-2.2.4/gems/dynflow-0.8.11/lib/dynflow/middleware/stack.rb:26:in `pass'
/git/.rvm/gems/ruby-2.2.4/gems/dynflow-0.8.11/lib/dynflow/middleware.rb:17:in `pass'
/git/foreman-tasks/app/lib/actions/middleware/keep_current_user.rb:30:in `block in run'
/git/foreman-tasks/app/lib/actions/middleware/keep_current_user.rb:53:in `restore_curent_user'
/git/foreman-tasks/app/lib/actions/middleware/keep_current_user.rb:30:in `run'
/git/.rvm/gems/ruby-2.2.4/gems/dynflow-0.8.11/lib/dynflow/middleware/stack.rb:22:in `call'
/git/.rvm/gems/ruby-2.2.4/gems/dynflow-0.8.11/lib/dynflow/middleware/stack.rb:26:in `pass'
/git/.rvm/gems/ruby-2.2.4/gems/dynflow-0.8.11/lib/dynflow/middleware.rb:17:in `pass'
/git/.rvm/gems/ruby-2.2.4/gems/dynflow-0.8.11/lib/dynflow/action/progress.rb:30:in `with_progress_calculation'
/git/.rvm/gems/ruby-2.2.4/gems/dynflow-0.8.11/lib/dynflow/action/progress.rb:16:in `run'
/git/.rvm/gems/ruby-2.2.4/gems/dynflow-0.8.11/lib/dynflow/middleware/stack.rb:22:in `call'
/git/.rvm/gems/ruby-2.2.4/gems/dynflow-0.8.11/lib/dynflow/middleware/stack.rb:26:in `pass'
/git/.rvm/gems/ruby-2.2.4/gems/dynflow-0.8.11/lib/dynflow/middleware.rb:17:in `pass'
/git/katello/app/lib/actions/middleware/keep_locale.rb:11:in `block in run'
/git/katello/app/lib/actions/middleware/keep_locale.rb:22:in `with_locale'
/git/katello/app/lib/actions/middleware/keep_locale.rb:11:in `run'
/git/.rvm/gems/ruby-2.2.4/gems/dynflow-0.8.11/lib/dynflow/middleware/stack.rb:22:in `call'
/git/.rvm/gems/ruby-2.2.4/gems/dynflow-0.8.11/lib/dynflow/middleware/stack.rb:26:in `pass'
/git/.rvm/gems/ruby-2.2.4/gems/dynflow-0.8.11/lib/dynflow/middleware.rb:17:in `pass'
/git/.rvm/gems/ruby-2.2.4/gems/dynflow-0.8.11/lib/dynflow/middleware.rb:30:in `run'
/git/.rvm/gems/ruby-2.2.4/gems/dynflow-0.8.11/lib/dynflow/middleware/stack.rb:22:in `call'
/git/.rvm/gems/ruby-2.2.4/gems/dynflow-0.8.11/lib/dynflow/middleware/world.rb:30:in `execute'
/git/.rvm/gems/ruby-2.2.4/gems/dynflow-0.8.11/lib/dynflow/action.rb:505:in `block (2 levels) in execute_run'
/git/.rvm/gems/ruby-2.2.4/gems/dynflow-0.8.11/lib/dynflow/action.rb:504:in `catch'

Expected results:

Associated Docker repositories are properly synced without error

Additional info:

As part of QCI we have integrated syncing Docker containers to Satellite for our OpenShift deployments. I generally do not have any problems when resyncing the repositories manually from the WebUI but I do see this associated error frequently when resyncing using the API.

Comment 1 Dylan Murray 2016-06-24 18:22:56 UTC
Created attachment 1172038 [details]
foreman-debug tarball

Comment 2 David Davis 2016-06-27 15:20:44 UTC
There's no rails log in your foreman_debug output. Are you running this in development? If so, can you attach your development.log?

Comment 3 Dylan Murray 2016-06-27 15:30:13 UTC
David, yes I am running in development. I was forced to tear down my environment over the weekend but I am recreating this and will attach the development log.

Comment 4 David Davis 2016-06-27 16:06:19 UTC
Dylan, awesome. Thanks.

Also, when you say in step 3 that you're hitting the api, do you mean the web api (ie /katello/api/v2/repositories/1/sync) or are you calling these dynflow actions directly in your code? If the latter, can you point me to the code in fusor? Thanks.

Comment 5 Dylan Murray 2016-06-27 16:56:45 UTC
David,

The latter, we are calling dynflow actions. I made a small commit to my fork here: https://github.com/dymurray/fusor/commit/33c20da50711f2ee48237189184d9207ea289876 to show the changes I am running.

https://github.com/dymurray/fusor/blob/33c20da50711f2ee48237189184d9207ea289876/server/app/lib/actions/fusor/content/manage_content.rb#L96 shows where the actual sync is being called.


https://github.com/dymurray/fusor/blob/33c20da50711f2ee48237189184d9207ea289876/server/app/lib/actions/fusor/deployment/prepare_org/create_docker_repository.rb#L29 shows where the repositories are added to the product.

I am still trying to reproduce, on top of this I am fighting some pulp errors with the CDN but should have something shortly. Thanks.

Comment 6 David Davis 2016-06-28 19:41:03 UTC
Dylan, since neither of us can reproduce this since you recreated your dev env, I'm going to close this out. I think it may have been a weird state you hit somehow. If you hit it again though, reopen this and attach your rails log. Thanks.

Comment 7 John Matthews 2016-08-02 19:40:42 UTC
I saw same Issue from ISO built on 8/1, using Sat 6.2 (RPM Environment)
David Gao saw same issue 2-3 days ago (Devel Env)

Scenario is I had a successful deployment, all content synced.
When I attempted to run a 2nd deployment I consistently hit the issue reported in comment #0.

Additionally, John Kim used same ISO, ran same scenario as me, his 2nd deployment was successful and did not see these issues.


Attaching production.log, I saw this in a RPM environment, not the DevelEnv.



gist /var/log/foreman/production.log
https://gist.github.com/c3ae76597b5df2458c2fe21eefb77715

[root@sat ~]# gist /var/log/messages
https://gist.github.com/b9b17270f48db62ea7130c19ce8e8e28

[root@sat ~]# rpm -qa | grep katello
katello-client-bootstrap-1.1.0-2.el7sat.noarch
tfm-rubygem-katello-3.0.0.68-1.el7sat.noarch
katello-server-ca-1.0-1.noarch
pulp-katello-1.0.1-1.el7sat.noarch
katello-service-3.0.0-10.el7sat.noarch
katello-3.0.0-10.el7sat.noarch
katello-common-3.0.0-10.el7sat.noarch
katello-default-ca-1.0-1.noarch
katello-certs-tools-2.4.0-1.el7sat.noarch
katello-debug-3.0.0-10.el7sat.noarch
katello-installer-base-3.0.0.56-1.el7sat.noarch
tfm-rubygem-hammer_cli_katello-0.0.22.23-1.el7sat.noarch
foreman-installer-katello-3.0.0.56-1.el7sat.noarch
katello-selinux-3.0.1.2-1.el7sat.noarch

Comment 8 John Matthews 2016-08-02 23:31:08 UTC
David, 

Here is some more information about the issue.
Problem is seen with several docker images, seems to always be with the 'latest' tag.

Below information gathered is for one docker image, 
  openshift/origin-docker-builder latest

I wonder if this is related to the docker image being updated frequently, looking at docker hub I see this image is changing several times a day.  Perhaps it's exposing a timing issue with syncs/indexing/etc?
 https://hub.docker.com/r/openshift/origin-custom-docker-builder/builds/



Katello is looking for a pulp unit with:
 manifest.digest = <sha256:4dc1392840f13b55cc6ff6e078b192bbc491a9a8d7ff3424dd1840564606dfea>, tag_name = <latest>

Issue seems to be that Pulp has a different 'manifest_digest' recorded for this docker image with tag latest.

From mongo(pulp_database)
  "manifest_digest" : "sha256:be40c37cff845eef7a069200eb39c14ad17563a77179cc25b5187c3d4b31ec52"

> db.units_docker_tag.find({"repo_id": "default_organization-fusor-origin-docker-builder", "name": "latest"})

{ "_id" : "3dfc272e-73aa-4a75-befe-197671dc958a", "pulp_user_metadata" : {  }, "_last_updated" : 1470106773, "name" : "latest", "manifest_digest" : "sha256:be40c37cff845eef7a069200eb39c14ad17563a77179cc25b5187c3d4b31ec52", "repo_id" : "default_organization-fusor-origin-docker-builder", "_ns" : "units_docker_tag", "_content_type_id" : "docker_tag" }


[root@sat ~]# gist /var/log/foreman/production.log
https://gist.github.com/c0b599dc635e69daf64e7ea8d8eea052


2016-08-02 18:59:41 [app] [E] JWM: index_db_docker_manifests:  manifest_json = <{"repository_memberships"=>["default_organization-fusor-origin-docker-builder"], "_s
torage_path"=>"/var/lib/pulp/content/units/docker_manifest/fc/76bcb968d17a1244c670ac219c2205087d7bf62ebcb638bebe1a625508dd42/sha256:4dc1392840f13b55cc6ff6e078b192bb
c491a9a8d7ff3424dd1840564606dfea", "name"=>"openshift/origin-docker-builder", "_last_updated"=>"2016-08-02T02:59:33Z", "fs_layers"=>[{"blob_sum"=>"sha256:a3ed95caeb
02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4"}, {"blob_sum"=>"sha256:a86b97e1f9bbb4a3ac5b05d13dbf7f28b3a5370bbc29411c4db46bd78f5dc3b8"}, {"blob_sum"=>"sha
256:05f9edd312a328f4c03430c0de45c569f4e710aafdeddcce4f65da5e82db33dc"}, {"blob_sum"=>"sha256:a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4"}, {"b
lob_sum"=>"sha256:a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4"}, {"blob_sum"=>"sha256:da71393503ec9136cf62056c233f5d25b878e372c840170d91d65f8cd
f94def2"}, {"blob_sum"=>"sha256:a3ed95caeb02ffe68cdd9fd84406680ae93d633cb16422d00e8a7c22955b46d4"}], "schema_version"=>1, "downloaded"=>true, "tag"=>"latest", "pulp
_user_metadata"=>{}, "_content_type_id"=>"docker_manifest", "_id"=>"47ce7d25-f4ff-4ba8-b775-5f6c2d34fd26", "children"=>{}, "digest"=>"sha256:4dc1392840f13b55cc6ff6e
078b192bbc491a9a8d7ff3424dd1840564606dfea", "_href"=>"/pulp/api/v2/content/units/docker_manifest/47ce7d25-f4ff-4ba8-b775-5f6c2d34fd26/"}>


2016-08-02 18:59:41 [app] [E] JWM:  manifest = <openshift/origin-docker-builder>, manifest.id = <245>, manifest.digest = <sha256:4dc1392840f13b55cc6ff6e078b192bbc49
1a9a8d7ff3424dd1840564606dfea>, tag_name = <latest>, tag = <>, repository_id = <8>

2016-08-02 18:59:41 [foreman-tasks/action] [E] undefined method `[]' for nil:NilClass (NoMethodError)
 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.68/app/models/katello/glue/pulp/repo.rb:462:in `create_docker_tag'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.68/app/models/katello/glue/pulp/repo.rb:443:in `block in index_db_docker_manifests'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.68/app/models/katello/glue/pulp/repo.rb:439:in `each'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.68/app/models/katello/glue/pulp/repo.rb:439:in `index_db_docker_manifests'
 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.68/app/models/katello/glue/pulp/repo.rb:845:in `index_content'



irb(main):001:0> ::Katello::Repository.find(8)
=> #<Katello::Repository id: 8, name: "origin-docker-builder", pulp_id: "default_organization-fusor-origin-docker-builder", created_at: "2016-08-02 01:34:10", updated_at: "2016-08-02 01:34:10", major: nil, minor: nil, gpg_key_id: nil, cp_label: nil, library_instance_id: nil, content_id: "1470101650453", arch: "noarch", label: "origin-docker-builder", content_view_version_id: 1, relative_path: "default_organization-fusor-origin-docker-builder", url: "http://registry-1.docker.io/", unprotected: true, content_type: "docker", product_id: 33, environment_id: 1, checksum_type: nil, docker_upstream_name: "openshift/origin-docker-builder", distribution_version: nil, distribution_arch: nil, distribution_bootable: nil, distribution_family: nil, distribution_variant: nil, distribution_uuid: nil, mirror_on_sync: true, download_policy: nil>

 `<main>'irb(main):005:0> ::Katello::DockerTag.where(:repository_id => 8, :name => "latest")
=> #<ActiveRecord::Relation [#<Katello::DockerTag id: 245, name: "latest", repository_id: 8, created_at: "2016-08-02 02:59:44", updated_at: "2016-08-02 02:59:44", uuid: "3dfc272e-73aa-4a75-befe-197671dc958a", docker_manifest_id: 245>]>


From mongo (pulp_database):

> db.units_docker_tag.find({"repo_id": "default_organization-fusor-origin-docker-builder", "name": "latest"})

{ "_id" : "3dfc272e-73aa-4a75-befe-197671dc958a", "pulp_user_metadata" : {  }, "_last_updated" : 1470106773, "name" : "latest", "manifest_digest" : "sha256:be40c37cff845eef7a069200eb39c14ad17563a77179cc25b5187c3d4b31ec52", "repo_id" : "default_organization-fusor-origin-docker-builder", "_ns" : "units_docker_tag", "_content_type_id" : "docker_tag" }




# vim /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.0.0.68/app/models/katello/glue/pulp/repo.rb


438       def index_db_docker_manifests
439         docker_manifests_json.each do |manifest_json|
440           manifest = DockerManifest.where(:uuid => manifest_json[:_id]).first_or_create
441           manifest.update_from_json(manifest_json)
442           Rails.logger.error "JWM: index_db_docker_manifests:  manifest_json = <#{manifest_json}>"
443           create_docker_tag(manifest, manifest_json[:tag])
444         end
445         DockerManifest.sync_repository_associations(self, pulp_docker_manifest_ids)
446       end
447
448       def docker_manifests_json
449         docker_manifests = []
450         pulp_docker_manifest_ids.each_slice(SETTINGS[:katello][:pulp][:bulk_load_size]) do |sub_list|
451           docker_manifests.concat(Katello.pulp_server.extensions.docker_manifest.find_all_by_unit_ids(sub_list))
452         end
453         docker_manifests
454       end
455
456       def create_docker_tag(manifest, tag_name)
457         tag = unit_search(:type_ids => [Runcible::Extensions::DockerTag.content_type],
458                           :filters => { :unit => { :manifest_digest => manifest.digest,
459                                                    :name => tag_name } }).first
460         Rails.logger.error "JWM:  manifest = <#{manifest}>, manifest.id = <#{manifest.id}>, manifest.digest = <#{manifest.digest}>, tag_name = <#{tag_name}>, ta    g = <#{tag}>, repository_id = <#{id}>"
461         DockerTag.where(:repository_id => id, :docker_manifest_id => manifest.id,
462                         :name => tag[:metadata][:name], :uuid => tag[:metadata][:_id]).first_or_create
463       end

Comment 11 Thom Carlin 2016-08-03 17:49:56 UTC
*** Bug 1363854 has been marked as a duplicate of this bug. ***

Comment 12 Thom Carlin 2016-08-03 17:52:05 UTC
I also encountered this on bare metal on QCI 1.0 (production environment)

Comment 14 Landon LaSmith 2016-08-03 19:28:25 UTC
Same issue after a successful RHEV+CFME+OSE deployment. Multiple attempts to deploy RHEV+CFME+OSE resulted in the same exceptions in production.log

Comment 16 Justin Sherrill 2016-08-03 20:06:17 UTC
Created redmine issue http://projects.theforeman.org/issues/15971 from this bug

Comment 17 Bryan Kearney 2016-08-03 22:16:44 UTC
Upstream bug assigned to daviddavis

Comment 18 Bryan Kearney 2016-08-03 22:16:49 UTC
Upstream bug assigned to daviddavis

Comment 19 Dylan Murray 2016-08-04 13:40:35 UTC
I have seen success with the above PR. Unable to reproduce using my own container and having success manually syncing the containers we use for QCI.

Comment 20 jcallaha 2016-08-05 20:11:46 UTC
Verified in Satellite 6.2.1 Snap 1.1

I sync'd the docker repo in the issue mentioned above (openshift/origin-custom-docker-builder) as well as one of my own repos. For mine, I kicked off builds before, during, and after I synchronized the repo. No issues seen during any sync process.

Comment 21 Bryan Kearney 2016-08-16 11:19:58 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2016:1615


Note You need to log in before you can comment on or make changes to this bug.