Bug 1257140 - multiple concurrent reposync breaks Satellite
multiple concurrent reposync breaks Satellite
Status: CLOSED CURRENTRELEASE
Product: Red Hat Satellite 6
Classification: Red Hat
Component: Pulp (Show other bugs)
6.1.0
Unspecified Unspecified
unspecified Severity unspecified (vote)
: Unspecified
: --
Assigned To: satellite6-bugs
Katello QA List
: Triaged
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2015-08-26 06:57 EDT by Lukas Pramuk
Modified: 2016-08-05 17:10 EDT (History)
5 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2016-08-02 19:26:21 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description Lukas Pramuk 2015-08-26 06:57:34 EDT
Description of problem:
Multiple concurrent reposync breaks Satellite.
A very useful tool to simulate concurrent pulp reposync is a hammer import repository-enable command.
After/during syncing of 4 repositories for each of 3 organization various errors starts to occur and Actions::Pulp::Repository::Sync have following results:
• RestClient::RequestTimeout
• StandardError: Abnormal termination

Afterall packages are not synced in repositories:
---
 	Red Hat Enterprise Linux 6 Server RPMs x86_64 6Server 	yum 	Pending ago 	
16060 Packages
0 Errata
	Red Hat Enterprise Linux 7 Server RPMs x86_64 7Server 	yum 	Warning ago 	
0 Packages
0 Errata
	RHN Tools for Red Hat Enterprise Linux 6 Server RPMs x86_64 6Server 	yum 	Error ago 	
0 Packages
0 Errata
	RHN Tools for Red Hat Enterprise Linux 7 Server RPMs x86_64 7Server 	yum 	Pending ago 	
0 Packages
0 Errata
---
Satellite is broken for some time (even simple requests timeouts):
# hammer -v --csv organization list
[[31mERROR[0m [34m2015-08-24 23:59:58[0m [36mException[0m] Error: Request Timeout
Error: Request Timeout
[[31mERROR[0m [34m2015-08-24 23:59:58[0m [36mException[0m] 

RestClient::RequestTimeout (Request Timeout):
    /usr/share/gems/gems/rest-client-1.6.7/lib/restclient/request.rb:184:in `rescue in transmit'
    /usr/share/gems/gems/rest-client-1.6.7/lib/restclient/request.rb:140:in `transmit'
    /usr/share/gems/gems/rest-client-1.6.7/lib/restclient/request.rb:64:in `execute'
    /usr/share/gems/gems/rest-client-1.6.7/lib/restclient/request.rb:33:in `execute'
    /usr/share/gems/gems/rest-client-1.6.7/lib/restclient/resource.rb:51:in `get'
    /usr/share/gems/gems/apipie-bindings-0.0.11/lib/apipie_bindings/api.rb:279:in `call_client'
    /usr/share/gems/gems/apipie-bindings-0.0.11/lib/apipie_bindings/api.rb:210:in `http_call'
    /usr/share/gems/gems/apipie-bindings-0.0.11/lib/apipie_bindings/api.rb:160:in `call'



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

How reproducible:
frequently

Steps to Reproduce:
1. Import 3 organizations using hammer import organization and upload manifests for each organization

2. Prepare csv file for repository-enablement (2 base channels and its 2 child channels)
# cat /tmp/exports/channels.csv
channel_id,channel_label,channel_name,number_of_packages,org_id
101,rhel-x86_64-server-6,Red Hat Enterprise Linux Server (v. 6 for 64-bit x86_64),0,
103,rhel-x86_64-server-7,Red Hat Enterprise Linux Server (v. 7 for 64-bit x86_64),0,
105,rhn-tools-rhel-x86_64-server-6,RHN Tools for RHEL (v. 6 for 64-bit x86_64),129,
106,rhn-tools-rhel-x86_64-server-7,RHN Tools for RHEL Server (v. 7 for x86_64),25,

3. Run repository-enablement (totalling 4 repos by 3 orgs)
# hammer import repository-enable --verbose --csv-file /tmp/exports/channels.csv --synchronize --wait
Importing from /tmp/exports/channels.csv
 Skipping clone-rhn-tools-rhel-x86_64-server-5 in organization 3
 Skipping clone-rhn-tools-rhel-x86_64-server-6 in organization 2
 Skipping clone-rhn-tools-rhel-x86_64-server-7 in organization 1
 Skipping custom-1 in organization 1
 Skipping custom-2 in organization 2
 Skipping custom-3 in organization 3
Enabling /content/dist/rhel/server/6/6Server/x86_64/os/Packages for channel rhel-x86_64-server-6 in org 3
Mapping redhat repository [[1, 101]->1].
Registering tasks for uuids: ["e2713aca-206a-4290-8c35-bac454f39dda"].
Starting thread for async tasks
Enabling /content/dist/rhel/server/6/6Server/x86_64/os/Packages for channel rhel-x86_64-server-6 in org 4
Mapping redhat repository [[2, 101]->2].
Registering tasks for uuids: ["5953408d-5a3d-4fdc-b137-858a3744ea08"].
Enabling /content/dist/rhel/server/6/6Server/x86_64/os/Packages for channel rhel-x86_64-server-6 in org 5
Mapping redhat repository [[3, 101]->3].
Registering tasks for uuids: ["cf608eeb-927a-4d3f-91a3-4be771ac2656"].
Enabling /content/dist/rhel/server/7/7Server/x86_64/os/Packages for channel rhel-x86_64-server-7 in org 3
Mapping redhat repository [[1, 103]->4].
Registering tasks for uuids: ["9fdbd3b0-430b-46a0-a517-418894989ebd"].
Enabling /content/dist/rhel/server/7/7Server/x86_64/os/Packages for channel rhel-x86_64-server-7 in org 4
Mapping redhat repository [[2, 103]->5].
Registering tasks for uuids: ["275d95f6-d128-453f-854d-84edc3b48e4a"].
Enabling /content/dist/rhel/server/7/7Server/x86_64/os/Packages for channel rhel-x86_64-server-7 in org 5
Mapping redhat repository [[3, 103]->6].
Registering tasks for uuids: ["95dc0482-317c-4a87-b571-69ff5e78d676"].
Enabling /content/dist/rhel/server/6/6Server/x86_64/rhn-tools/os/Packages for channel rhn-tools-rhel-x86_64-server-6 in org 3
Mapping redhat repository [[1, 105]->7].
Registering tasks for uuids: ["d6ae3658-fca3-4dc8-b8e6-5e5d012ccb93"].
Enabling /content/dist/rhel/server/6/6Server/x86_64/rhn-tools/os/Packages for channel rhn-tools-rhel-x86_64-server-6 in org 4
Mapping redhat repository [[2, 105]->8].
Registering tasks for uuids: ["3406fe03-fa4d-4394-9329-fc2434c17476"].
Enabling /content/dist/rhel/server/6/6Server/x86_64/rhn-tools/os/Packages for channel rhn-tools-rhel-x86_64-server-6 in org 5
Mapping redhat repository [[3, 105]->9].
Registering tasks for uuids: ["17a200a2-9661-4ebe-9e6b-befd80e75818"].
Enabling /content/dist/rhel/server/7/7Server/x86_64/rhn-tools/os/Packages for channel rhn-tools-rhel-x86_64-server-7 in org 3
Mapping redhat repository [[1, 106]->10].
Registering tasks for uuids: ["fbdd07a9-0175-4ff3-aeaf-19a4a06364e1"].
Enabling /content/dist/rhel/server/7/7Server/x86_64/rhn-tools/os/Packages for channel rhn-tools-rhel-x86_64-server-7 in org 4
Mapping redhat repository [[2, 106]->11].
Registering tasks for uuids: ["1e3da0b9-348f-441c-8414-664b5fa259d6"].
Enabling /content/dist/rhel/server/7/7Server/x86_64/rhn-tools/os/Packages for channel rhn-tools-rhel-x86_64-server-7 in org 5
Mapping redhat repository [[3, 106]->12].
Registering tasks for uuids: ["a22c71dc-8842-4156-9919-f580c2bff6fd"].
Waiting for async tasks to finish
Asynchronous tasks: 0 of 12 done (~ 0.50%)
...
Asynchronous tasks: 0 of 12 done (~26.15%)
Exiting: Request Timeout
Summary
  Mapped 12 redhat_repositories.


Actual results:
errors: pending,paused tasks, repos not synced, all requests even simple ones all timeout

Expected results:
finished tasks, repos synced, no breakdown
Comment 2 Lukas Pramuk 2015-08-26 07:03:20 EDT
Dynflow Console:

3: Actions::Pulp::Repository::Sync (error) [ 20564.02s / 1364.26s ] Skip

Started at: 2015-08-24 22:06:48 UTC

Ended at: 2015-08-25 03:49:32 UTC

Real time: 20564.02s

Execution time (excluding suspended state): 1364.26s

Input:

---
pulp_id: Organization__2-Red_Hat_Enterprise_Linux_Server-Red_Hat_Enterprise_Linux_7_Server_RPMs_x86_64_7Server
task_id: 
remote_user: admin-7805fa1f
remote_cp_user: admin
locale: en

Output:

---
pulp_tasks:
- exception: 
  task_type: pulp.server.managers.repo.sync.sync
  _href: /pulp/api/v2/tasks/72ff1b71-7ab2-4ad8-9c07-9eaa3763f9ae/
  task_id: 72ff1b71-7ab2-4ad8-9c07-9eaa3763f9ae
  tags:
  - pulp:repository:Organization__2-Red_Hat_Enterprise_Linux_Server-Red_Hat_Enterprise_Linux_7_Server_RPMs_x86_64_7Server
  - pulp:action:sync
  finish_time: '2015-08-25T01:44:04Z'
  _ns: task_status
  start_time: '2015-08-25T01:22:15Z'
  traceback: 
  spawned_tasks:
  - _href: /pulp/api/v2/tasks/f6fdd921-ea9d-429a-8fb9-0546d7dc035d/
    task_id: f6fdd921-ea9d-429a-8fb9-0546d7dc035d
  - _href: /pulp/api/v2/tasks/34a17ce5-eb7a-400e-a3a7-b28323516156/
    task_id: 34a17ce5-eb7a-400e-a3a7-b28323516156
  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-1@<SATFQDN>.dq
  state: finished
  worker_name: reserved_resource_worker-1@<SATFQDN>
  result:
    importer_type_id: yum_importer
    importer_id: yum_importer
    exception: 
    repo_id: Organization__2-Red_Hat_Enterprise_Linux_Server-Red_Hat_Enterprise_Linux_7_Server_RPMs_x86_64_7Server
    removed_count: 0
    started: '2015-08-25T01:22:15Z'
    _ns: repo_sync_results
    completed: '2015-08-25T01:44:03Z'
    traceback: 
    summary:
      content:
        state: FINISHED
      comps:
        state: FINISHED
      distribution:
        state: FINISHED
      errata:
        state: FINISHED
      metadata:
        state: FINISHED
    added_count: 87
    error_message: 
    updated_count: 8048
    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:
        items_total: 0
        state: FINISHED
        error_details: []
        items_left: 0
      errata:
        state: FINISHED
      metadata:
        state: FINISHED
    id: 55dbc863bbedbc1750d9e4e1
    result: success
  error: 
  _id:
    $oid: 55db9578ab45c64aeaf3245d
  id: 55dbc346bbedbc1733ba559d
- exception: 
  task_type: pulp.server.managers.repo.publish.publish
  _href: /pulp/api/v2/tasks/f6fdd921-ea9d-429a-8fb9-0546d7dc035d/
  task_id: f6fdd921-ea9d-429a-8fb9-0546d7dc035d
  tags:
  - pulp:repository:Organization__2-Red_Hat_Enterprise_Linux_Server-Red_Hat_Enterprise_Linux_7_Server_RPMs_x86_64_7Server
  - pulp:action:publish
  finish_time: 
  start_time: '2015-08-25T03:31:22Z'
  traceback: 
  spawned_tasks: []
  progress_report: {}
  queue: reserved_resource_worker-1@<SATFQDN>.dq
  state: running
  worker_name: reserved_resource_worker-1@<SATFQDN>
  result: 
  error: 
  _id:
    $oid: 55dbc863ab45c64aeaf32472
  id: 55dbe189bbedbc1733bc690c
- exception: 
  task_type: pulp.server.managers.repo.publish.publish
  _href: /pulp/api/v2/tasks/34a17ce5-eb7a-400e-a3a7-b28323516156/
  task_id: 34a17ce5-eb7a-400e-a3a7-b28323516156
  tags:
  - pulp:repository:Organization__2-Red_Hat_Enterprise_Linux_Server-Red_Hat_Enterprise_Linux_7_Server_RPMs_x86_64_7Server
  - pulp:action:publish
  finish_time: 
  start_time: 
  traceback: 
  spawned_tasks: []
  progress_report: {}
  queue: reserved_resource_worker-1@<SATFQDN>.dq
  state: waiting
  worker_name: reserved_resource_worker-1@d<SATFQDN>
  result: 
  error: 
  _id:
    $oid: 55dbc864ab45c64aeaf32473
  id: 55dbe18bbbedbc1733bc6910
poll_attempts:
  total: 1159
  failed: 0

Error:

StandardError

Abnormal termination (previous state: suspended)

---
- /opt/rh/ruby193/root/usr/share/gems/gems/algebrick-0.4.0/lib/algebrick.rb:859:in
  `block in assigns'
- /opt/rh/ruby193/root/usr/share/gems/gems/algebrick-0.4.0/lib/algebrick.rb:858:in
  `tap'
- /opt/rh/ruby193/root/usr/share/gems/gems/algebrick-0.4.0/lib/algebrick.rb:858:in
  `assigns'
- /opt/rh/ruby193/root/usr/share/gems/gems/algebrick-0.4.0/lib/algebrick.rb:138:in
  `match_value'
- /opt/rh/ruby193/root/usr/share/gems/gems/algebrick-0.4.0/lib/algebrick.rb:116:in
  `block in match'
- /opt/rh/ruby193/root/usr/share/gems/gems/algebrick-0.4.0/lib/algebrick.rb:115:in
  `each'
- /opt/rh/ruby193/root/usr/share/gems/gems/algebrick-0.4.0/lib/algebrick.rb:115:in
  `match'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/execution_plan/steps/error.rb:12:in
  `new'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/world.rb:204:in
  `block (2 levels) in consistency_check'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/world.rb:202:in
  `each'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/world.rb:202:in
  `block in consistency_check'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/world.rb:193:in
  `each'
- /opt/rh/ruby193/root/usr/share/gems/gems/dynflow-0.7.7.9/lib/dynflow/world.rb:193:in
  `consistency_check'
- /opt/rh/ruby193/root/usr/share/gems/gems/foreman-tasks-0.6.15.4/lib/foreman_tasks/dynflow.rb:52:in
  `block in initialize!'
- /opt/rh/ruby193/root/usr/share/gems/gems/foreman-tasks-0.6.15.4/lib/foreman_tasks/dynflow.rb:40:in
  `tap'
- /opt/rh/ruby193/root/usr/share/gems/gems/foreman-tasks-0.6.15.4/lib/foreman_tasks/dynflow.rb:40:in
  `initialize!'
- /opt/rh/ruby193/root/usr/share/gems/gems/foreman-tasks-0.6.15.4/lib/foreman_tasks/engine.rb:81:in
  `block in <class:Engine>'
- /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/initializable.rb:30:in
  `instance_exec'
- /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/initializable.rb:30:in
  `run'
- /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/initializable.rb:55:in
  `block in run_initializers'
- /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/initializable.rb:54:in
  `each'
- /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/initializable.rb:54:in
  `run_initializers'
- /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/application.rb:136:in
  `initialize!'
- /opt/rh/ruby193/root/usr/share/gems/gems/railties-3.2.8/lib/rails/railtie/configurable.rb:30:in
  `method_missing'
- /usr/share/foreman/config/environment.rb:12:in `<top (required)>'
- /opt/rh/ruby193/root/usr/share/rubygems/rubygems/custom_require.rb:36:in `require'
- /opt/rh/ruby193/root/usr/share/rubygems/rubygems/custom_require.rb:36:in `require'
- /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/dependencies.rb:251:in
  `block in require'
- /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/dependencies.rb:236:in
  `load_dependency'
- /opt/rh/ruby193/root/usr/share/gems/gems/activesupport-3.2.8/lib/active_support/dependencies.rb:251:in
  `require'
- /opt/rh/ruby193/root/usr/share/gems/gems/foreman-tasks-0.6.15.4/lib/foreman_tasks/dynflow/daemon.rb:15:in
  `run'
- /opt/rh/ruby193/root/usr/share/gems/gems/foreman-tasks-0.6.15.4/lib/foreman_tasks/dynflow/daemon.rb:50:in
  `block in run_background'
- /opt/rh/ruby193/root/usr/share/gems/gems/daemons-1.1.4/lib/daemons/application.rb:249:in
  `call'
- /opt/rh/ruby193/root/usr/share/gems/gems/daemons-1.1.4/lib/daemons/application.rb:249:in
  `block in start_proc'
- /opt/rh/ruby193/root/usr/share/gems/gems/daemons-1.1.4/lib/daemons/daemonize.rb:197:in
  `call'
- /opt/rh/ruby193/root/usr/share/gems/gems/daemons-1.1.4/lib/daemons/daemonize.rb:197:in
  `call_as_daemon'
- /opt/rh/ruby193/root/usr/share/gems/gems/daemons-1.1.4/lib/daemons/application.rb:253:in
  `start_proc'
- /opt/rh/ruby193/root/usr/share/gems/gems/daemons-1.1.4/lib/daemons/application.rb:293:in
  `start'
- /opt/rh/ruby193/root/usr/share/gems/gems/daemons-1.1.4/lib/daemons/controller.rb:70:in
  `run'
- /opt/rh/ruby193/root/usr/share/gems/gems/daemons-1.1.4/lib/daemons.rb:195:in `block
  in run_proc'
- /opt/rh/ruby193/root/usr/share/gems/gems/daemons-1.1.4/lib/daemons/cmdline.rb:109:in
  `call'
- /opt/rh/ruby193/root/usr/share/gems/gems/daemons-1.1.4/lib/daemons/cmdline.rb:109:in
  `catch_exceptions'
- /opt/rh/ruby193/root/usr/share/gems/gems/daemons-1.1.4/lib/daemons.rb:194:in `run_proc'
- /opt/rh/ruby193/root/usr/share/gems/gems/foreman-tasks-0.6.15.4/lib/foreman_tasks/dynflow/daemon.rb:43:in
  `run_background'
- /usr/bin/foreman-tasks:5:in `<main>'

5: Actions::ElasticSearch::Repository::IndexContent (pending)
15: Actions::Katello::Repository::ErrataMail (pending)
17: Actions::Katello::Repository::Sync (pending)
20: Actions::Pulp::Repository::RegenerateApplicability (pending)
Comment 4 Lukas Pramuk 2015-08-27 07:01:10 EDT
Another story on a beefy machine (80 cpus,128G ram):

All tasks ended with success but repos are still not synced:

Red Hat Enterprise Linux 5 Server RPMs x86_64 5Server 	yum 	Success about 10 hours ago 	
147 Packages
0 Errata
Red Hat Enterprise Linux 6 Server RPMs x86_64 6Server 	yum 	Success about 10 hours ago 	
1 Packages
0 Errata
Red Hat Enterprise Linux 7 Server RPMs x86_64 7Server 	yum 	Success about 10 hours ago 	
80 Packages
0 Errata

False success looks like this:
 Output:

Cancelled.
New packages: 11 (27.4 GB).

or 

 Output:

Cancelled.
Processing metadata.


content(yum importer):  CANCELLED   vs. task: SUCCESS



 3: Actions::Pulp::Repository::Sync (success) [ 792.11s / 145.69s ]

Started at: 2015-08-26 23:54:22 UTC

Ended at: 2015-08-27 00:07:34 UTC

Real time: 792.11s

Execution time (excluding suspended state): 145.69s

Input:

---
pulp_id: Organization__3-Red_Hat_Enterprise_Linux_Server-Red_Hat_Enterprise_Linux_5_Server_RPMs_x86_64_5Server
task_id: 
remote_user: admin-ebe0dbb7
remote_cp_user: admin
locale: en

Output:

---
pulp_tasks:
- exception: 
  task_type: pulp.server.managers.repo.sync.sync
  _href: /pulp/api/v2/tasks/e937625b-60b2-4e2e-b9f9-5a2669296180/
  task_id: e937625b-60b2-4e2e-b9f9-5a2669296180
  tags:
  - pulp:repository:Organization__3-Red_Hat_Enterprise_Linux_Server-Red_Hat_Enterprise_Linux_5_Server_RPMs_x86_64_5Server
  - pulp:action:sync
  finish_time: '2015-08-27T00:07:24Z'
  _ns: task_status
  start_time: '2015-08-26T23:54:22Z'
  traceback: 
  spawned_tasks:
  - _href: /pulp/api/v2/tasks/acfacf79-8583-45a3-b6ae-326456c4873b/
    task_id: acfacf79-8583-45a3-b6ae-326456c4873b
  - _href: /pulp/api/v2/tasks/8f409ed5-9b6c-4d33-906d-ed686621cb6e/
    task_id: 8f409ed5-9b6c-4d33-906d-ed686621cb6e
  progress_report:
    yum_importer:
      content:
        size_total: 39840329747
        items_left: 16716
        items_total: 16747
        state: CANCELLED
        size_left: 39675977992
        details:
          rpm_total: 16747
          rpm_done: 31
          drpm_total: 0
          drpm_done: 0
        error_details: []
      comps:
        state: NOT_STARTED
      distribution:
        items_total: 0
        state: NOT_STARTED
        error_details: []
        items_left: 0
      errata:
        state: NOT_STARTED
      metadata:
        state: FINISHED
  queue: reserved_resource_worker-2@<SAT_FQDN>.dq
  state: canceled
  worker_name: reserved_resource_worker-2@<SAT_FQDN>
  result:
    importer_type_id: yum_importer
    importer_id: yum_importer
    exception: 
    repo_id: Organization__3-Red_Hat_Enterprise_Linux_Server-Red_Hat_Enterprise_Linux_5_Server_RPMs_x86_64_5Server
    removed_count: 0
    started: '2015-08-26T23:54:22Z'
    _ns: repo_sync_results
    completed: '2015-08-27T00:07:24Z'
    traceback: 
    summary:
      content:
        state: CANCELLED
      comps:
        state: NOT_STARTED
      distribution:
        state: NOT_STARTED
      errata:
        state: NOT_STARTED
      metadata:
        state: FINISHED
    added_count: 1
    error_message: 
    updated_count: 147
    details:
      content:
        size_total: 39840329747
        items_left: 16716
        items_total: 16747
        state: CANCELLED
        size_left: 39675977992
        details:
          rpm_total: 16747
          rpm_done: 31
          drpm_total: 0
          drpm_done: 0
        error_details: []
      comps:
        state: NOT_STARTED
      distribution:
        items_total: 0
        state: NOT_STARTED
        error_details: []
        items_left: 0
      errata:
        state: NOT_STARTED
      metadata:
        state: FINISHED
    id: 55de54bcfa36adb47a098665
    result: canceled
  error: 
  _id:
    $oid: 55de51ae887de0c2e86a1825
  id: 55de51aefa36adb5cd3dbf9f
- exception: 
  task_type: pulp.server.managers.repo.publish.publish
  _href: /pulp/api/v2/tasks/acfacf79-8583-45a3-b6ae-326456c4873b/
  task_id: acfacf79-8583-45a3-b6ae-326456c4873b
  tags:
  - pulp:repository:Organization__3-Red_Hat_Enterprise_Linux_Server-Red_Hat_Enterprise_Linux_5_Server_RPMs_x86_64_5Server
  - pulp:action:publish
  finish_time: '2015-08-27T00:07:25Z'
  _ns: task_status
  start_time: '2015-08-27T00:07:24Z'
  traceback: 
  spawned_tasks: []
  progress_report: {}
  queue: reserved_resource_worker-7@<SAT_FQDN>.dq
  state: finished
  worker_name: reserved_resource_worker-7@<SAT_FQDN>
  result:
    exception: 
    repo_id: Organization__3-Red_Hat_Enterprise_Linux_Server-Red_Hat_Enterprise_Linux_5_Server_RPMs_x86_64_5Server
    started: '2015-08-27T00:07:24Z'
    _ns: repo_publish_results
    completed: '2015-08-27T00:07:25Z'
    traceback: 
    distributor_type_id: nodes_http_distributor
    summary: succeeded
    error_message: 
    details:
      unit_count: 148
    distributor_id: Organization__3-Red_Hat_Enterprise_Linux_Server-Red_Hat_Enterprise_Linux_5_Server_RPMs_x86_64_5Server_nodes
    id: 55de54bdfa36adb537bab78c
    result: success
  error: 
  _id:
    $oid: 55de54bc887de0c2e86a1848
  id: 55de54bcfa36adb5cd3dc9b4
- exception: 
  task_type: pulp.server.managers.repo.publish.publish
  _href: /pulp/api/v2/tasks/8f409ed5-9b6c-4d33-906d-ed686621cb6e/
  task_id: 8f409ed5-9b6c-4d33-906d-ed686621cb6e
  tags:
  - pulp:repository:Organization__3-Red_Hat_Enterprise_Linux_Server-Red_Hat_Enterprise_Linux_5_Server_RPMs_x86_64_5Server
  - pulp:action:publish
  finish_time: '2015-08-27T00:07:26Z'
  _ns: task_status
  start_time: '2015-08-27T00:07:25Z'
  traceback: 
  spawned_tasks: []
  progress_report:
    Organization__3-Red_Hat_Enterprise_Linux_Server-Red_Hat_Enterprise_Linux_5_Server_RPMs_x86_64_5Server:
    - num_success: 1
      description: Copying files
      step_type: save_tar
      items_total: 1
      state: FINISHED
      error_details: []
      details: ''
      num_failures: 0
      step_id: 0701eca2-0449-483a-be27-e2b8d5ae98bc
      num_processed: 1
    - num_success: 1
      description: Initializing repo metadata
      step_type: initialize_repo_metadata
      items_total: 1
      state: FINISHED
      error_details: []
      details: ''
      num_failures: 0
      step_id: 583eee7d-efac-48c0-ad34-f0ddc98369a7
      num_processed: 1
    - num_success: 0
      description: Publishing Distribution files
      step_type: distribution
      items_total: 0
      state: FINISHED
      error_details: []
      details: ''
      num_failures: 0
      step_id: 4985a7ee-926a-4a26-9f73-081f2bd07324
      num_processed: 0
    - num_success: 147
      description: Publishing RPMs
      step_type: rpms
      items_total: 697
      state: FINISHED
      error_details: []
      details: ''
      num_failures: 0
      step_id: c03360b5-3e32-4eda-8f24-161c914cadfc
      num_processed: 147
    - num_success: 0
      description: Publishing Delta RPMs
      step_type: drpms
      items_total: 1
      state: SKIPPED
      error_details: []
      details: ''
      num_failures: 0
      step_id: 676729e5-0743-432f-bbed-4ab26a44b6fb
      num_processed: 0
    - num_success: 0
      description: Publishing Errata
      step_type: errata
      items_total: 0
      state: FINISHED
      error_details: []
      details: ''
      num_failures: 0
      step_id: c5142b0b-169b-4e8d-813b-ff3e9989190a
      num_processed: 0
    - num_success: 0
      description: Publishing Comps file
      step_type: comps
      items_total: 0
      state: FINISHED
      error_details: []
      details: ''
      num_failures: 0
      step_id: 5fa113ab-e604-479b-b9c7-78a4a0ca98b8
      num_processed: 0
    - num_success: 1
      description: Publishing Metadata.
      step_type: metadata
      items_total: 1
      state: FINISHED
      error_details: []
      details: ''
      num_failures: 0
      step_id: c2805ba7-8c2a-4ea7-8a87-45b1cd79a763
      num_processed: 1
    - num_success: 1
      description: Closing repo metadata
      step_type: close_repo_metadata
      items_total: 1
      state: FINISHED
      error_details: []
      details: ''
      num_failures: 0
      step_id: e438c0e0-3aca-4eaf-8126-cc01b3e1e389
      num_processed: 1
    - num_success: 0
      description: Generating sqlite files
      step_type: generate sqlite
      items_total: 1
      state: SKIPPED
      error_details: []
      details: ''
      num_failures: 0
      step_id: 0d4b6641-c1b8-4cd6-bec6-cec0775f85e9
      num_processed: 0
    - num_success: 1
      description: Publishing files to web
      step_type: publish_directory
      items_total: 1
      state: FINISHED
      error_details: []
      details: ''
      num_failures: 0
      step_id: 5846237b-a8db-4642-a9af-d75180c279b3
      num_processed: 1
    - num_success: 1
      description: Writing Listings File
      step_type: initialize_repo_metadata
      items_total: 1
      state: FINISHED
      error_details: []
      details: ''
      num_failures: 0
      step_id: 50174b30-9163-4142-ae77-f99ca3c081ea
      num_processed: 1
  queue: reserved_resource_worker-7@<SAT_FQDN>.dq
  state: finished
  worker_name: reserved_resource_worker-7@<SAT_FQDN>
  result:
    exception: 
    repo_id: Organization__3-Red_Hat_Enterprise_Linux_Server-Red_Hat_Enterprise_Linux_5_Server_RPMs_x86_64_5Server
    started: '2015-08-27T00:07:25Z'
    _ns: repo_publish_results
    completed: '2015-08-27T00:07:26Z'
    traceback: 
    distributor_type_id: yum_distributor
    summary:
      generate sqlite: SKIPPED
      initialize_repo_metadata: FINISHED
      rpms: FINISHED
      close_repo_metadata: FINISHED
      drpms: SKIPPED
      comps: FINISHED
      distribution: FINISHED
      metadata: FINISHED
      publish_directory: FINISHED
      errata: FINISHED
      save_tar: FINISHED
    error_message: 
    details:
    - num_success: 1
      description: Copying files
      step_type: save_tar
      items_total: 1
      state: FINISHED
      error_details: []
      details: ''
      num_failures: 0
      step_id: 0701eca2-0449-483a-be27-e2b8d5ae98bc
      num_processed: 1
    - num_success: 1
      description: Initializing repo metadata
      step_type: initialize_repo_metadata
      items_total: 1
      state: FINISHED
      error_details: []
      details: ''
      num_failures: 0
      step_id: 583eee7d-efac-48c0-ad34-f0ddc98369a7
      num_processed: 1
    - num_success: 0
      description: Publishing Distribution files
      step_type: distribution
      items_total: 0
      state: FINISHED
      error_details: []
      details: ''
      num_failures: 0
      step_id: 4985a7ee-926a-4a26-9f73-081f2bd07324
      num_processed: 0
    - num_success: 147
      description: Publishing RPMs
      step_type: rpms
      items_total: 697
      state: FINISHED
      error_details: []
      details: ''
      num_failures: 0
      step_id: c03360b5-3e32-4eda-8f24-161c914cadfc
      num_processed: 147
    - num_success: 0
      description: Publishing Delta RPMs
      step_type: drpms
      items_total: 1
      state: SKIPPED
      error_details: []
      details: ''
      num_failures: 0
      step_id: 676729e5-0743-432f-bbed-4ab26a44b6fb
      num_processed: 0
    - num_success: 0
      description: Publishing Errata
      step_type: errata
      items_total: 0
      state: FINISHED
      error_details: []
      details: ''
      num_failures: 0
      step_id: c5142b0b-169b-4e8d-813b-ff3e9989190a
      num_processed: 0
    - num_success: 0
      description: Publishing Comps file
      step_type: comps
      items_total: 0
      state: FINISHED
      error_details: []
      details: ''
      num_failures: 0
      step_id: 5fa113ab-e604-479b-b9c7-78a4a0ca98b8
      num_processed: 0
    - num_success: 1
      description: Publishing Metadata.
      step_type: metadata
      items_total: 1
      state: FINISHED
      error_details: []
      details: ''
      num_failures: 0
      step_id: c2805ba7-8c2a-4ea7-8a87-45b1cd79a763
      num_processed: 1
    - num_success: 1
      description: Closing repo metadata
      step_type: close_repo_metadata
      items_total: 1
      state: FINISHED
      error_details: []
      details: ''
      num_failures: 0
      step_id: e438c0e0-3aca-4eaf-8126-cc01b3e1e389
      num_processed: 1
    - num_success: 0
      description: Generating sqlite files
      step_type: generate sqlite
      items_total: 1
      state: SKIPPED
      error_details: []
      details: ''
      num_failures: 0
      step_id: 0d4b6641-c1b8-4cd6-bec6-cec0775f85e9
      num_processed: 0
    - num_success: 1
      description: Publishing files to web
      step_type: publish_directory
      items_total: 1
      state: FINISHED
      error_details: []
      details: ''
      num_failures: 0
      step_id: 5846237b-a8db-4642-a9af-d75180c279b3
      num_processed: 1
    - num_success: 1
      description: Writing Listings File
      step_type: initialize_repo_metadata
      items_total: 1
      state: FINISHED
      error_details: []
      details: ''
      num_failures: 0
      step_id: 50174b30-9163-4142-ae77-f99ca3c081ea
      num_processed: 1
    distributor_id: Organization__3-Red_Hat_Enterprise_Linux_Server-Red_Hat_Enterprise_Linux_5_Server_RPMs_x86_64_5Server
    id: 55de54befa36adb537bab795
    result: success
  error: 
  _id:
    $oid: 55de54bc887de0c2e86a1849
  id: 55de54bcfa36adb5cd3dc9b8
poll_attempts:
  total: 56
  failed: 1
Comment 6 Lukas Pramuk 2015-08-27 07:40:19 EDT
Pulp logs exhibit multiple tracebacks:
- ImporterConduitException: ids don't match ... ...
- CancelException

It seems that multiple workers are clashing with each other and thus causing cancelation


Aug 26 20:06:52 dell-per920-02 pulp: pulp.server.async.scheduler:ERROR: Workers 'reserved_resource_worker-0@<SAT_FQDN>' has gone missing, removing from list of workers
Aug 26 20:06:52 dell-per920-02 pulp: pulp.server.async.tasks:ERROR: The worker named reserved_resource_worker-0@<SAT_FQDN> is missing. Canceling the tasks in its queue.
Aug 26 20:07:09 dell-per920-02 pulp: celery.worker.strategy:INFO: Received task: pulp.server.async.tasks._queue_reserved_task[eb7ad873-a996-41f1-9437-4ecad8d2a7e1]
Aug 26 20:07:09 dell-per920-02 pulp: kombu.transport.qpid:INFO: Connected to qpid with SASL mechanism ANONYMOUS
Aug 26 20:07:09 dell-per920-02 pulp: celery.worker.control:INFO: Terminating 1e439637-1034-4018-8a58-fa9e9f396e9f (15)
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064) Exception from server setting progress for report [yum_importer]
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064) Traceback (most recent call last):
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib/python2.6/site-packages/pulp/plugins/conduits/mixins.py", line 628, in set_progress
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     TaskStatusManager.update_task_status(self.task_id, delta)
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib/python2.6/site-packages/pulp/server/async/task_status_manager.py", line 194, in update_task_status
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     task_status = TaskStatus.get_collection().find_one({'task_id': task_id})
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib/python2.6/site-packages/pulp/server/db/connection.py", line 167, in retry
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     return method(*args, **kwargs)
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/collection.py", line 596, in find_one
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     for result in self.find(spec_or_id, *args, **kwargs).limit(-1):
Aug 26 20:07:14 dell-per920-02 pulp: pulp.server.async.tasks:INFO: Task canceled: 1e439637-1034-4018-8a58-fa9e9f396e9f.
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/cursor.py", line 814, in next
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     if len(self.__data) or self._refresh():
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/cursor.py", line 763, in _refresh
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     self.__uuid_subtype))
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/cursor.py", line 700, in __send_message
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     **kwargs)
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/mongo_client.py", line 991, in _send_message_with_response
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     return self.__send_and_receive(message, sock_info)
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/mongo_client.py", line 969, in __send_and_receive
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     return self.__receive_message_on_socket(1, request_id, sock_info)
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/mongo_client.py", line 958, in __receive_message_on_socket
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:INFO: Downloading 16059 RPMs.
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     struct.unpack("<i", header[8:12])[0])
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064) AssertionError: ids don't match 448857977 667810171
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: Progress value: {'content': {'size_total': 0, 'items_left': 0, 'items_total': 0, 'state': 'CANCELLED', 'size_left': 0, 'details': {'rpm_total': 0, 'rpm_done': 0, 'drpm_total': 0, 'drpm_done': 0}, 'error_details': []}, 'comps': {'state': 'NOT_STARTED'}, 'distribution': {'items_total': 0, 'state': 'NOT_STARTED', 'error_details': [], 'items_left': 0}, 'errata': {'state': 'NOT_STARTED'}, 'metadata': {'state': 'FINISHED'}}
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064) Exception from server requesting all units of type [rpm]
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064) Traceback (most recent call last):
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib/python2.6/site-packages/pulp/plugins/conduits/mixins.py", line 220, in search_all_units
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     for pulp_unit in units:
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/cursor.py", line 814, in next
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     if len(self.__data) or self._refresh():
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/cursor.py", line 763, in _refresh
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     self.__uuid_subtype))
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/cursor.py", line 700, in __send_message
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     **kwargs)
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/mongo_client.py", line 991, in _send_message_with_response
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     return self.__send_and_receive(message, sock_info)
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/mongo_client.py", line 969, in __send_and_receive
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     return self.__receive_message_on_socket(1, request_id, sock_info)
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/mongo_client.py", line 954, in __receive_message_on_socket
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     header = self.__receive_data_on_socket(16, sock_info)
Aug 26 20:07:14 dell-per920-02 pulp: pulp.server.async.scheduler:ERROR: Workers 'reserved_resource_worker-1@dell-per920-02.khw.lab.eng.bos.redhat.com' has gone missing, removing from list of workers
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/mongo_client.py", line 942, in __receive_data_on_socket
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     chunk = sock_info.sock.recv(length)
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib/python2.6/site-packages/pulp/server/async/tasks.py", line 466, in sigterm_handler
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     handler()
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib/python2.6/site-packages/pulp_rpm/plugins/importers/yum/importer.py", line 75, in cancel_sync_repo
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     self._current_sync.cancel()
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib/python2.6/site-packages/pulp_rpm/plugins/importers/yum/sync.py", line 451, in cancel
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     self.set_progress()
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib/python2.6/site-packages/pulp_rpm/plugins/importers/yum/sync.py", line 71, in set_progress
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     self.sync_conduit.set_progress(self.progress_status)
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib/python2.6/site-packages/pulp/plugins/conduits/mixins.py", line 628, in set_progress
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     TaskStatusManager.update_task_status(self.task_id, delta)
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib/python2.6/site-packages/pulp/server/async/task_status_manager.py", line 194, in update_task_status
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     task_status = TaskStatus.get_collection().find_one({'task_id': task_id})
Aug 26 20:07:14 dell-per920-02 pulp: pulp.server.async.tasks:ERROR: The worker named reserved_resource_worker-1@dell-per920-02.khw.lab.eng.bos.redhat.com is missing. Canceling the tasks in its queue.
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib/python2.6/site-packages/pulp/server/db/connection.py", line 167, in retry
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     return method(*args, **kwargs)
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/collection.py", line 596, in find_one
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     for result in self.find(spec_or_id, *args, **kwargs).limit(-1):
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/cursor.py", line 814, in next
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     if len(self.__data) or self._refresh():
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/cursor.py", line 763, in _refresh
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     self.__uuid_subtype))
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/mongo_client.py", line 991, in _send_message_with_response
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     return self.__send_and_receive(message, sock_info)
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/mongo_client.py", line 969, in __send_and_receive
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     return self.__receive_message_on_socket(1, request_id, sock_info)
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/mongo_client.py", line 958, in __receive_message_on_socket
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064)     struct.unpack("<i", header[8:12])[0])
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: (111669-00064) ImporterConduitException: ids don't match 448857977 667810171
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064) sync failed
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064) Traceback (most recent call last):
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)   File "/usr/lib/python2.6/site-packages/pulp_rpm/plugins/importers/yum/sync.py", line 114, in run
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)     self.update_content(metadata_files)
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)   File "/usr/lib/python2.6/site-packages/pulp_rpm/plugins/importers/yum/sync.py", line 272, in update_content
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)     rpms_to_download, drpms_to_download = self._decide_what_to_download(metadata_files)
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)   File "/usr/lib/python2.6/site-packages/pulp_rpm/plugins/importers/yum/sync.py", line 290, in _decide_what_to_download
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)     rpms_to_download, rpms_count, rpms_total_size = self._decide_rpms_to_download(metadata_files)
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)   File "/usr/lib/python2.6/site-packages/pulp_rpm/plugins/importers/yum/sync.py", line 329, in _decide_rpms_to_download
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)     self.sync_conduit)
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)   File "/usr/lib/python2.6/site-packages/pulp_rpm/plugins/importers/yum/existing.py", line 103, in check_all_and_associate
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)     sync_conduit.search_all_units):
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)   File "/usr/lib/python2.6/site-packages/pulp_rpm/plugins/importers/yum/existing.py", line 159, in get_all_existing_units
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)     for result in search_method(unit_type, criteria):
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)   File "/usr/lib/python2.6/site-packages/pulp/plugins/conduits/mixins.py", line 220, in search_all_units
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)     for pulp_unit in units:
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/cursor.py", line 814, in next
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)     if len(self.__data) or self._refresh():
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/cursor.py", line 763, in _refresh
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)     self.__uuid_subtype))
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/cursor.py", line 700, in __send_message
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)     **kwargs)
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/mongo_client.py", line 991, in _send_message_with_response
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)     return self.__send_and_receive(message, sock_info)
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/mongo_client.py", line 969, in __send_and_receive
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)     return self.__receive_message_on_socket(1, request_id, sock_info)
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/mongo_client.py", line 954, in __receive_message_on_socket
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)     header = self.__receive_data_on_socket(16, sock_info)
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/mongo_client.py", line 942, in __receive_data_on_socket
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)     chunk = sock_info.sock.recv(length)
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)   File "/usr/lib/python2.6/site-packages/pulp/server/async/tasks.py", line 466, in sigterm_handler
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)     handler()
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)   File "/usr/lib/python2.6/site-packages/pulp_rpm/plugins/importers/yum/importer.py", line 75, in cancel_sync_repo
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)     self._current_sync.cancel()
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)   File "/usr/lib/python2.6/site-packages/pulp_rpm/plugins/importers/yum/sync.py", line 451, in cancel
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)     self.set_progress()
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)   File "/usr/lib/python2.6/site-packages/pulp_rpm/plugins/importers/yum/sync.py", line 71, in set_progress
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)     self.sync_conduit.set_progress(self.progress_status)
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)   File "/usr/lib/python2.6/site-packages/pulp/plugins/conduits/mixins.py", line 628, in set_progress
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)     TaskStatusManager.update_task_status(self.task_id, delta)
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)   File "/usr/lib/python2.6/site-packages/pulp/server/async/task_status_manager.py", line 194, in update_task_status
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)     task_status = TaskStatus.get_collection().find_one({'task_id': task_id})
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)   File "/usr/lib/python2.6/site-packages/pulp/server/db/connection.py", line 167, in retry
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)     return method(*args, **kwargs)
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/collection.py", line 596, in find_one
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)     for result in self.find(spec_or_id, *args, **kwargs).limit(-1):
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/cursor.py", line 814, in next
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)     if len(self.__data) or self._refresh():
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/cursor.py", line 763, in _refresh
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)     self.__uuid_subtype))
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/cursor.py", line 700, in __send_message
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)     **kwargs)
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/mongo_client.py", line 991, in _send_message_with_response
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)     return self.__send_and_receive(message, sock_info)
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/mongo_client.py", line 969, in __send_and_receive
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)     return self.__receive_message_on_socket(1, request_id, sock_info)
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)   File "/usr/lib64/python2.6/site-packages/pymongo/mongo_client.py", line 958, in __receive_message_on_socket
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064)     struct.unpack("<i", header[8:12])[0])
Aug 26 20:07:14 dell-per920-02 pulp: pulp_rpm.plugins.importers.yum.sync:ERROR: (111669-00064) ImporterConduitException: ids don't match 448857977 667810171
...
Aug 26 20:07:14 dell-per920-02 pulp: pulp.server.async.tasks:ERROR: The worker named reserved_resource_worker-6@<SAT_FQDN> is missing. Canceling the tasks in its queue.
Aug 26 20:07:14 dell-per920-02 pulp: pulp.plugins.conduits.mixins:ERROR: Progress value: {'content': {'size_total': 29390006304, 'items_left': 16059, 'items_total': 16059, 'state': 'CANCELLED', 'size_left': 29390006304, 'details': {'rpm_total': 16059, 'rpm_done': 0, 'drpm_total': 0, 'drpm_done': 0}, 'error_details': []}, 'comps': {'state': 'NOT_STARTED'}, 'distribution': {'items_total': 0, 'state': 'NOT_STARTED', 'error_details': [], 'items_left': 0}, 'errata': {'state': 'NOT_STARTED'}, 'metadata': {'state': 'FINISHED'}}
Aug 26 20:07:14 dell-per920-02 pulp: pulp.server.async.worker_watcher:INFO: New worker 'reserved_resource_worker-3@<SAT_FQDN>' discovered
Aug 26 20:07:14 dell-per920-02 pulp: pulp.server.managers.repo.sync:ERROR: (111669-00064) Exception caught from plugin during sync for repo [Organization__3-Red_Hat_Enterprise_Linux_Server-Red_Hat_Enterprise_Linux_6_Server_RPMs_x86_64_6Server]
Aug 26 20:07:14 dell-per920-02 pulp: pulp.server.managers.repo.sync:ERROR: (111669-00064) Traceback (most recent call last):
Aug 26 20:07:14 dell-per920-02 pulp: pulp.server.managers.repo.sync:ERROR: (111669-00064)   File "/usr/lib/python2.6/site-packages/pulp/server/managers/repo/sync.py", line 164, in _do_sync
Aug 26 20:07:14 dell-per920-02 pulp: pulp.server.managers.repo.sync:ERROR: (111669-00064)     sync_report = sync_repo(transfer_repo, conduit, call_config)
Aug 26 20:07:14 dell-per920-02 pulp: pulp.server.managers.repo.sync:ERROR: (111669-00064)   File "/usr/lib/python2.6/site-packages/pulp/server/async/tasks.py", line 483, in wrap_f
Aug 26 20:07:14 dell-per920-02 pulp: pulp.server.managers.repo.sync:ERROR: (111669-00064)     return f(*args, **kwargs)
Aug 26 20:07:14 dell-per920-02 pulp: pulp.server.managers.repo.sync:ERROR: (111669-00064)   File "/usr/lib/python2.6/site-packages/pulp_rpm/plugins/importers/yum/importer.py", line 67, in sync_repo
Aug 26 20:07:14 dell-per920-02 pulp: pulp.server.managers.repo.sync:ERROR: (111669-00064)     report = self._current_sync.run()
Aug 26 20:07:14 dell-per920-02 pulp: pulp.server.managers.repo.sync:ERROR: (111669-00064)   File "/usr/lib/python2.6/site-packages/pulp_rpm/plugins/importers/yum/sync.py", line 159, in run
Aug 26 20:07:14 dell-per920-02 pulp: pulp.server.managers.repo.sync:ERROR: (111669-00064)     self.set_progress()
Aug 26 20:07:14 dell-per920-02 pulp: pulp.server.managers.repo.sync:ERROR: (111669-00064)   File "/usr/lib/python2.6/site-packages/pulp_rpm/plugins/importers/yum/sync.py", line 73, in set_progress
Aug 26 20:07:14 dell-per920-02 pulp: pulp.server.managers.repo.sync:ERROR: (111669-00064)     raise CancelException
Aug 26 20:07:14 dell-per920-02 pulp: pulp.server.managers.repo.sync:ERROR: (111669-00064) CancelException
Comment 7 Michael Hrivnak 2015-10-01 10:38:46 EDT
I don't see any evidence that the workers are conflicting with each other. The problem appears to be that worker heartbeats are not being received or processed, and so pulp thinks workers have died. By default, pulp waits for 5 minutes before it cancels a missing worker's tasks.

On a resource-starved system, it's possible that either the worker or some other critical process was OOM-killed, or is simply unresponsive for an extended period. Given your initial description that satellite's UI was unresponsive, etc., this is a possible explanation. However on your "beefy" system, that seems less likely.

The attached foreman debug outputs do not appear to be from the same time periods as your text pastes into the comments, and I'm not able to find similar errors in /var/log/messages. Can you reproduce this and attach a foreman debug file that contains the errors?

I want to look for anything like oom-kills, qpid errors (this is the mechanism for worker heartbeats), database-related errors, or anything else that might explain why a worker would not send a successful heartbeat for an extended period.
Comment 8 Michael Hrivnak 2016-03-29 12:25:22 EDT
Multiple problems were discovered in the qpid client library that caused symptoms like this. Those have been fixed and released with Sat 6.1, so I suspect this problem won't occur again. I suggest closing this issue unless there is additional information.
Comment 9 Bryan Kearney 2016-07-26 11:25:24 EDT
Moving 6.2 bugs out to sat-backlog.
Comment 10 Bryan Kearney 2016-07-26 11:41:01 EDT
Moving 6.2 bugs out to sat-backlog.
Comment 12 Brad Buckingham 2016-08-02 19:26:21 EDT
Based on comment 8 and lack of response to the NEEDINFO request, I am going to close this bug.  If the issue persists on Satellite 6.2, please do re-open with an updated foreman-debug.

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