Red Hat Satellite engineering is moving the tracking of its product development work on Satellite to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "Satellite project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs will be migrated starting at the end of May. If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "Satellite project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/SAT-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
Bug 1264330 - Pulp repo sync taks never completing
Summary: Pulp repo sync taks never completing
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Red Hat Satellite
Classification: Red Hat
Component: Pulp
Version: 6.1.2
Hardware: Unspecified
OS: Unspecified
urgent
high
Target Milestone: Unspecified
Assignee: satellite6-bugs
QA Contact: Katello QA List
URL:
Whiteboard:
Depends On:
Blocks: 1122832
TreeView+ depends on / blocked
 
Reported: 2015-09-18 08:30 UTC by Peter Vreman
Modified: 2019-09-12 08:56 UTC (History)
5 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2015-12-30 08:40:31 UTC
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)
sosreport (8.75 MB, application/x-xz)
2015-09-18 14:36 UTC, Peter Vreman 		no flags Details
View All


Links
System ID Private Priority Status Summary Last Updated
Red Hat Bugzilla 1279502 0 unspecified CLOSED Pulp tasks randomly stuck at waiting or running 2022-07-09 07:29:35 UTC

Description Peter Vreman 2015-09-18 08:30:55 UTC 
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:
Comment 1 Peter Vreman 2015-09-18 09:12:09 UTC 
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
Comment 2 Peter Vreman 2015-09-18 09:42:20 UTC 
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.
Comment 3 Peter Vreman 2015-09-18 14:36:23 UTC 
Created attachment 1074946 [details]
sosreport
Comment 7 Peter Vreman 2015-11-12 09:35:57 UTC 
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
Comment 10 Peter Vreman 2015-12-30 08:40:12 UTC 
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.
Note You need to log in before you can comment on or make changes to this bug.