Description of problem: We have pulp repo sync tasks that are staying on incomplete state for 6+ hours. Therefor the Katello repository sync tasks will also not complete. From the logging it looks like the yum_import finished quickly, but the overall task state is not updated. It happends with both standard RedHat repositories as well as with Custom product repositories. It happend both with only a single repo sync task running (Custom product case) as well as many (50+) concurrent tasks during a daily RedHat repo sync. ----- Incomplete task 1 of RedHat Repository: [crash] root@li-lc-1578:~# date Fri Sep 18 08:07:04 GMT 2015 [crash] root@li-lc-1578:~# pulp-admin tasks list | grep -B6 38c30954-c2bd-4a85-b6c6-951a0b23bee2 Operations: sync Resources: Hilti-Oracle_Java__for_RHEL_Server_-Red_Hat_Enterprise_Linux_6_Serv er_-_Oracle_Java_RPMs_x86_64_6Server (repository) State: Running Start Time: 2015-09-18T02:00:23Z Finish Time: Incomplete Task Id: 38c30954-c2bd-4a85-b6c6-951a0b23bee2 [crash] root@li-lc-1578:~# grep 38c30954-c2bd-4a85-b6c6-951a0b23bee2 /var/log/messages Sep 18 02:00:23 li-lc-1578 pulp: celery.worker.strategy:INFO: Received task: pulp.server.managers.repo.sync.sync[38c30954-c2bd-4a85-b6c6-951a0b23bee2] Sep 18 02:00:47 li-lc-1578 pulp: pulp.server.event.http:INFO: (29212-74560) {'call_report': {u'exception': None, u'task_type': u'pulp.server.managers.repo.sync.sync', u'task_id': u'38c30954-c2bd-4a85-b6c6-951a0b23bee2', u'tags': [u'pulp:repository:Hilti-Oracle_Java__for_RHEL_Server_-Red_Hat_Enterprise_Linux_6_Server_-_Oracle_Java_RPMs_x86_64_6Server', u'pulp:action:sync'], u'finish_time': None, u'_ns': u'task_status', u'start_time': u'2015-09-18T02:00:23Z', u'traceback': None, u'spawned_tasks': [], u'progress_report': {u'yum_importer': {u'content': {u'size_total': 0, u'items_left': 0, u'items_total': 0, u'state': u'FINISHED', u'size_left': 0, u'details': {u'rpm_total': 0, u'rpm_done': 0, u'drpm_total': 0, u'drpm_done': 0}, u'error_details': []}, u'comps': {u'state': u'FINISHED'}, u'distribution': {u'items_total': 0, u'state': u'FINISHED', u'error_details': [], u'items_left': 0}, u'errata': {u'state': u'FINISHED'}, u'metadata': {u'state': u'FINISHED'}}}, u'state': u'running', u'worker_name': u'reserved_resource_worker-5@li-lc-1578', u'result': None, u'error': None, u'_id': ObjectId('55fb7037874b58303c5d7e5b'), u'id': u'55fb70370586fe0ea2c21ceb'}, 'event_type': 'repo.sync.finish', 'payload': {'importer_id': u'yum_importer', 'exception': None, 'repo_id': u'Hilti-Oracle_Java__for_RHEL_Server_-Red_Hat_Enterprise_Linux_6_Server_-_Oracle_Java_RPMs_x86_64_6Server', 'traceback': None, 'started': '2015-09-18T02:00:23Z', '_ns': u'repo_sync_results', 'completed': '2015-09-18T02:00:47Z', 'importer_type_id': u'yum_importer', 'error_message': None, 'summary': {'content': {'state': 'FINISHED'}, 'comps': {'state': 'FINISHED'}, 'distribution': {'state': 'FINISHED'}, 'errata': {'state': 'FINISHED'}, 'metadata': {'state': 'FINISHED'}}, 'added_count': 0, 'result': 'success', 'updated_count': 17, 'details': {'content': {'size_total': 0, 'items_left': 0, 'items_total': 0, 'state': 'FINISHED', 'size_left': 0, 'details': {'rpm_total': 0, 'rpm_done': 0, 'drpm_total': 0, 'drpm_done': 0}, 'error_details': []}, 'comps': {'state': 'FINISHED'}, 'distribution': {' ----- Incomplete task 2 with Custom Product: [crash] root@li-lc-1578:~# pulp-admin tasks list | grep -B6 aa993623-b01b-49ec-ba7f-0ac6d892ac0b Operations: sync Resources: Hilti-HOIPRODUCTS-HOIPRODUCTS-1_0_0-hf9 (repository) State: Running Start Time: 2015-09-17T20:08:52Z Finish Time: Incomplete Task Id: aa993623-b01b-49ec-ba7f-0ac6d892ac0b [crash] root@li-lc-1578:~# date Fri Sep 18 08:24:19 GMT 2015 [crash] root@li-lc-1578:~# grep aa993623-b01b-49ec-ba7f-0ac6d892ac0b /var/log/messages Sep 17 20:08:52 li-lc-1578 pulp: celery.worker.strategy:INFO: Received task: pulp.server.managers.repo.sync.sync[aa993623-b01b-49ec-ba7f-0ac6d892ac0b] Sep 17 20:08:58 li-lc-1578 pulp: pulp.server.event.http:INFO: (29249-25184) {'call_report': {u'exception': None, u'task_type': u'pulp.server.managers.repo.sync.sync', u'task_id': u'aa993623-b01b-49ec-ba7f-0ac6d892ac0b', u'tags': [u'pulp:repository:Hilti-HOIPRODUCTS-HOIPRODUCTS-1_0_0-hf9', u'pulp:action:sync'], u'finish_time': None, u'_ns': u'task_status', u'start_time': u'2015-09-17T20:08:52Z', u'traceback': None, u'spawned_tasks': [], u'progress_report': {u'yum_importer': {u'content': {u'size_total': 80203, u'items_left': 0, u'items_total': 3, u'state': u'FINISHED', u'size_left': 0, u'details': {u'rpm_total': 3, u'rpm_done': 3, u'drpm_total': 0, u'drpm_done': 0}, u'error_details': []}, u'comps': {u'state': u'FINISHED'}, u'distribution': {u'items_total': 0, u'state': u'FINISHED', u'error_details': [], u'items_left': 0}, u'errata': {u'state': u'FINISHED'}, u'metadata': {u'state': u'FINISHED'}}}, u'state': u'running', u'worker_name': u'reserved_resource_worker-3@li-lc-1578', u'result': None, u'error': None, u'_id': ObjectId('55fb1dd4874b58303c5d7e55'), u'id': u'55fb1dd40586fe0ea2c21cb7'}, 'event_type': 'repo.sync.finish', 'payload': {'importer_id': u'yum_importer', 'exception': None, 'repo_id': u'Hilti-HOIPRODUCTS-HOIPRODUCTS-1_0_0-hf9', 'traceback': None, 'started': '2015-09-17T20:08:52Z', '_ns': u'repo_sync_results', 'completed': '2015-09-17T20:08:58Z', 'importer_type_id': u'yum_importer', 'error_message': None, 'summary': {'content': {'state': 'FINISHED'}, 'comps': {'state': 'FINISHED'}, 'distribution': {'state': 'FINISHED'}, 'errata': {'state': 'FINISHED'}, 'metadata': {'state': 'FINISHED'}}, 'added_count': 3, 'result': 'success', 'updated_count': 10, 'details': {'content': {'size_total': 80203, 'items_left': 0, 'items_total': 3, 'state': 'FINISHED', 'size_left': 0, 'details': {'rpm_total': 3, 'rpm_done': 3, 'drpm_total': 0, 'drpm_done': 0}, 'error_details': []}, 'comps': {'state': 'FINISHED'}, 'distribution': {'items_total': 0, 'state': 'FINISHED', 'error_details': [], 'items_left': 0}, 'errata': {'state': 'FINISHED'}, 'metadata' Pulp versions from standard 6.1.2: [crash] root@li-lc-1578:~# rpm -qa | grep pulp | sort mod_wsgi-3.4-1.pulp.el6sat.x86_64 pulp-admin-client-2.6.0.15-1.el6_6sat.noarch pulp-docker-plugins-0.2.5-1.el6_6sat.noarch pulp-katello-0.5-1.el6_6sat.noarch pulp-nodes-common-2.6.0.15-1.el6_6sat.noarch pulp-nodes-parent-2.6.0.15-1.el6_6sat.noarch pulp-puppet-admin-extensions-2.6.0.15-1.el6_6sat.noarch pulp-puppet-plugins-2.6.0.15-1.el6_6sat.noarch pulp-puppet-tools-2.6.0.15-1.el6_6sat.noarch pulp-rpm-admin-extensions-2.6.0.15-1.el6_6sat.noarch pulp-rpm-handlers-2.6.0.15-1.el6_6sat.noarch pulp-rpm-plugins-2.6.0.15-1.el6_6sat.noarch pulp-selinux-2.6.0.15-1.el6_6sat.noarch pulp-server-2.6.0.15-1.el6_6sat.noarch python-isodate-0.5.0-4.pulp.el6_6sat.noarch python-kombu-3.0.24-10.pulp.el6_6sat.noarch python-pulp-agent-lib-2.6.0.15-1.el6_6sat.noarch python-pulp-bindings-2.6.0.15-1.el6_6sat.noarch python-pulp-client-lib-2.6.0.15-1.el6_6sat.noarch python-pulp-common-2.6.0.15-1.el6_6sat.noarch python-pulp-docker-common-0.2.5-1.el6_6sat.noarch python-pulp-puppet-common-2.6.0.15-1.el6_6sat.noarch python-pulp-rpm-common-2.6.0.15-1.el6_6sat.noarch rubygem-smart_proxy_pulp-1.0.1.2-1.el6_6sat.noarch Version-Release number of selected component (if applicable): How reproducible: Steps to Reproduce: 1. Sync 50+ RedHat repositories concurrent 2. 3. Actual results: A couple of tasks will stay on incomplete in Pulp and on Running in Katello Expected results: All tasks finish Additional info:
After restarting Satellite 6 i have now the following tasks for the above mentiond Custom Product "Hilti-HOIPRODUCTS-HOIPRODUCTS-1_0_0-hf9" that did not finish. The task_id changed to cancelled aa993623-b01b-49ec-ba7f-0ac6d892ac0b, but it now has a new unstarted task in Waiting: [crash] root@li-lc-1578:~# pulp-admin tasks list | grep -B1 -A5 Hilti-HOIPRODUCTS-HOIPRODUCTS-1_0_0-hf9 Operations: publish Resources: Hilti-HOIPRODUCTS-HOIPRODUCTS-1_0_0-hf9 (repository) State: Successful Start Time: 2015-09-17T20:08:31Z Finish Time: 2015-09-17T20:08:31Z Task Id: 6da37080-7415-4fb0-8da2-6fed57bbd783 Operations: sync Resources: Hilti-HOIPRODUCTS-HOIPRODUCTS-1_0_0-hf9 (repository) State: Cancelled Start Time: 2015-09-17T20:08:52Z Finish Time: Incomplete Task Id: aa993623-b01b-49ec-ba7f-0ac6d892ac0b Operations: publish Resources: Hilti-HOIPRODUCTS-HOIPRODUCTS-1_0_0-hf9 (repository) State: Waiting Start Time: Unstarted Finish Time: Incomplete Task Id: f8c4984c-3b01-459b-b01b-8d174c55d850
To try to recover i tried: - Restarting Satellite katello-service stop & start - Reboot Satellite server Both did not help. The resuming of the task still gives: {"pulp_tasks"=> [{"exception"=>nil, "task_type"=>"pulp.server.managers.repo.sync.sync", "_href"=>"/pulp/api/v2/tasks/269d201e-e868-4789-824b-4adefd0332bf/", "task_id"=>"269d201e-e868-4789-824b-4adefd0332bf", "tags"=> ["pulp:repository:Hilti-HOIPRODUCTS-HOIPRODUCTS-1_0_0-hf9", "pulp:action:sync"], "finish_time"=>nil, "_ns"=>"task_status", "start_time"=>"2015-09-18T09:30:21Z", "traceback"=>nil, "spawned_tasks"=>[], "progress_report"=> {"yum_importer"=> {"content"=> {"size_total"=>0, "items_left"=>0, "items_total"=>0, "state"=>"FINISHED", "size_left"=>0, "details"=> {"rpm_total"=>0, "rpm_done"=>0, "drpm_total"=>0, "drpm_done"=>0}, "error_details"=>[]}, "comps"=>{"state"=>"FINISHED"}, "distribution"=> {"items_total"=>0, "state"=>"FINISHED", "error_details"=>[], "items_left"=>0}, "errata"=>{"state"=>"FINISHED"}, "metadata"=>{"state"=>"FINISHED"}}}, "queue"=>"reserved_resource_worker-3", "state"=>"running", "worker_name"=>"reserved_resource_worker-3@li-lc-1578", "result"=>nil, "error"=>nil, "_id"=>{"$oid"=>"55fbd9ac9696a0d0902b3a1a"}, "id"=>"55fbd9ad0586fe0e30c37a9a"}], "poll_attempts"=>{"total"=>2619, "failed"=>0}} The yum_importer finished again correctly, but the overall pulp task still is in running state.
Created attachment 1074946 [details] sosreport
Still seeing this problem with Sat6.1.3, see the number of poll_attemps in the task below. Looks related to BZ1268756. Because from a timing perspective the never completing Sync is there since i tried to reproduce BZ1268756. 97 2015-11-10 16:19:54: logrotate -f -v /etc/logrotate.d Hanging task from dynflow console seen: Action: Actions::Pulp::Repository::Sync State: waiting for Pulp to finish the task Input: {"pulp_id"=> "Hilti-Red_Hat_Enterprise_Linux_Server_-_Extended_Update_Support-Red_Hat_Satellite_Tools_6_1_for_RHEL_6_Server_-_EUS_RPMs_x86_64_6_5", "task_id"=>nil, "remote_user"=>"hoici-4dbfe556", "remote_cp_user"=>"hoici", "locale"=>"en"} Output: {"pulp_tasks"=> [{"exception"=>nil, "task_type"=>"pulp.server.managers.repo.sync.sync", "_href"=>"/pulp/api/v2/tasks/aad03d1a-2279-41b5-b08d-25da14954f96/", "task_id"=>"aad03d1a-2279-41b5-b08d-25da14954f96", "tags"=> ["pulp:repository:Hilti-Red_Hat_Enterprise_Linux_Server_-_Extended_Update_Support-Red_Hat_Satellite_Tools_6_1_for_RHEL_6_Server_-_EUS_RPMs_x86_64_6_5", "pulp:action:sync"], "finish_time"=>nil, "_ns"=>"task_status", "start_time"=>"2015-11-10T16:19:12Z", "traceback"=>nil, "spawned_tasks"=>[], "progress_report"=> {"yum_importer"=> {"content"=> {"size_total"=>0, "items_left"=>0, "items_total"=>0, "state"=>"FINISHED", "size_left"=>0, "details"=> {"rpm_total"=>0, "rpm_done"=>0, "drpm_total"=>0, "drpm_done"=>0}, "error_details"=>[]}, "comps"=>{"state"=>"FINISHED"}, "distribution"=> {"items_total"=>0, "state"=>"FINISHED", "error_details"=>[], "items_left"=>0}, "errata"=>{"state"=>"FINISHED"}, "metadata"=>{"state"=>"FINISHED"}}}, "queue"=>"reserved_resource_worker-3", "state"=>"running", "worker_name"=>"reserved_resource_worker-3@li-lc-1578", "result"=>nil, "error"=>nil, "_id"=>{"$oid"=>"56421900d746ee9805a8f469"}, "id"=>"564219000586fe0e43e9feaa"}], "poll_attempts"=>{"total"=>8936, "failed"=>0}} /var/log/messages: Nov 10 16:19:56 li-lc-1578 pulp: pulp.server.db.connection:INFO: Mongo database for connection is version 2.4.6 Nov 10 16:19:57 li-lc-1578 pulp: pulp.plugins.loader.manager:INFO: Loaded plugin yum_clone_distributor for types: rpm,srpm,drpm,erratum,distribution,package_catego ry,package_group Nov 10 16:19:57 li-lc-1578 pulp: pulp.plugins.loader.manager:INFO: Loaded plugin yum_distributor for types: rpm,srpm,drpm,erratum,package_group,package_category,di stribution,yum_repo_metadata_file Nov 10 16:19:57 li-lc-1578 pulp: pulp.plugins.loader.manager:INFO: Loaded plugin export_distributor for types: rpm,srpm,drpm,erratum,distribution,package_category, package_group Nov 10 16:19:57 li-lc-1578 pulp: pulp.plugins.loader.manager:INFO: Loaded plugin iso_distributor for types: iso Nov 10 16:19:57 li-lc-1578 pulp: pulp.plugins.loader.manager:INFO: Loaded plugin docker_distributor_web for types: docker_image Nov 10 16:19:57 li-lc-1578 pulp: pulp.plugins.loader.manager:INFO: Loaded plugin docker_distributor_export for types: docker_image Nov 10 16:19:57 li-lc-1578 pulp: pulp.plugins.loader.manager:INFO: Loaded plugin nodes_http_distributor for types: node Nov 10 16:19:57 li-lc-1578 pulp: pulp.plugins.loader.manager:INFO: Loaded plugin puppet_distributor for types: puppet_module Nov 10 16:19:57 li-lc-1578 pulp: pulp.plugins.loader.manager:INFO: Loaded plugin puppet_file_distributor for types: puppet_module Nov 10 16:19:57 li-lc-1578 pulp: pulp.plugins.loader.manager:INFO: Loaded plugin puppet_install_distributor for types: puppet_module Nov 10 16:19:57 li-lc-1578 pulp: pulp.plugins.loader.manager:INFO: Loaded plugin group_export_distributor for types: rpm,srpm,drpm,erratum,distribution,package_cat egory,package_group Nov 10 16:19:57 li-lc-1578 pulp: pulp.plugins.loader.manager:INFO: Loaded plugin yum_importer for types: distribution,drpm,erratum,package_group,package_category,r pm,srpm,yum_repo_metadata_file,package_environment Nov 10 16:19:57 li-lc-1578 pulp: pulp.plugins.loader.manager:INFO: Loaded plugin iso_importer for types: iso Nov 10 16:19:57 li-lc-1578 pulp: pulp.plugins.loader.manager:INFO: Loaded plugin docker_importer for types: docker_image Nov 10 16:19:57 li-lc-1578 pulp: pulp.plugins.loader.manager:INFO: Loaded plugin puppet_importer for types: puppet_module Nov 10 16:19:57 li-lc-1578 pulp: pulp.plugins.loader.manager:INFO: Loaded plugin yum_profiler for types: rpm,erratum Nov 10 16:19:57 li-lc-1578 pulp: pulp.plugins.loader.manager:INFO: Loaded plugin node for types: node,repository Nov 10 16:19:57 li-lc-1578 pulp: pulp.plugins.loader.manager:INFO: Loaded plugin puppet_whole_repo_profiler for types: puppet_module Nov 10 16:19:57 li-lc-1578 pulp: pulp.plugins.loader.manager:INFO: Loaded plugin yum for types: rpm Nov 10 16:19:57 li-lc-1578 pulp: pulp.plugins.loader.manager:INFO: Loaded plugin rhui for types: rpm Nov 10 16:19:57 li-lc-1578 pulp: gofer.messaging.adapter.qpid.connection:INFO: connecting: URL: ssl://li-lc-1578.hag.hilti.com|SSL: ca: /etc/pki/katello/certs/kate llo-default-ca.crt|key: None|certificate: /etc/pki/katello/qpid_client_striped.crt|host-validation: False Nov 10 16:19:57 li-lc-1578 pulp: gofer.messaging.adapter.qpid.connection:INFO: connected: ssl://li-lc-1578.hag.hilti.com Nov 10 16:19:57 li-lc-1578 pulp: pulp.server.agent.direct.services:INFO: Task reply handler, started. Nov 10 16:19:57 li-lc-1578 pulp: pulp.server.agent.direct.services:INFO: AMQP reply handler started Nov 10 16:19:57 li-lc-1578 pulp: pulp.server.webservices.application:INFO: ************************************************************* Nov 10 16:19:57 li-lc-1578 pulp: pulp.server.webservices.application:INFO: The Pulp server has been successfully initialized Nov 10 16:19:57 li-lc-1578 pulp: pulp.server.webservices.application:INFO: ************************************************************* Nov 10 16:19:57 li-lc-1578 pulp: gofer.messaging.adapter.qpid.connection:INFO: connecting: URL: ssl://li-lc-1578.hag.hilti.com|SSL: ca: /etc/pki/katello/certs/kate llo-default-ca.crt|key: None|certificate: /etc/pki/katello/qpid_client_striped.crt|host-validation: False Nov 10 16:19:57 li-lc-1578 pulp: gofer.messaging.adapter.qpid.connection:INFO: connected: ssl://li-lc-1578.hag.hilti.com
Closing issue did not happen anymore since the upgrade to 6.1.5, the fix of https://bugzilla.redhat.com/show_bug.cgi?id=1279502 solved this issue.