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.
Created attachment 1172038 [details] foreman-debug tarball
There's no rails log in your foreman_debug output. Are you running this in development? If so, can you attach your development.log?
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.
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.
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.
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.
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
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
*** Bug 1363854 has been marked as a duplicate of this bug. ***
I also encountered this on bare metal on QCI 1.0 (production environment)
Same issue after a successful RHEV+CFME+OSE deployment. Multiple attempts to deploy RHEV+CFME+OSE resulted in the same exceptions in production.log
Created redmine issue http://projects.theforeman.org/issues/15971 from this bug
Upstream bug assigned to daviddavis
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.
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.
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