Katello::error::pulperror task canceled

katello_user · August 13, 2018, 10:21am

Problem:

While syncing a repository I am getting the following error:

katello::error::pulperror task canceled

The entire error message is like this:

Action:
Actions::Pulp::Repository::Sync
Input:
{"pulp_id"=>"d450d3ca-e3af-4099-bdee-05c33d5c3d0a",
 "task_id"=>nil,
 "source_url"=>nil,
 "options"=>{},
 "remote_user"=>"admin",
 "remote_cp_user"=>"admin",
 "locale"=>"en"}
Output:
{"pulp_tasks"=>
  [{"exception"=>nil,
    "task_type"=>"pulp.server.managers.repo.sync.sync",
    "_href"=>"/pulp/api/v2/tasks/f53c9015-ca56-45f6-b105-be97b09c23aa/",
    "task_id"=>"f53c9015-ca56-45f6-b105-be97b09c23aa",
    "tags"=>
     ["pulp:repository:d450d3ca-e3af-4099-bdee-05c33d5c3d0a",
      "pulp:action:sync"],
    "finish_time"=>"2018-08-13T07:52:31Z",
    "_ns"=>"task_status",
    "start_time"=>"2018-08-13T07:45:19Z",
    "traceback"=>nil,
    "spawned_tasks"=>
     [{"_href"=>"/pulp/api/v2/tasks/a5874638-c6fe-4bf6-8962-b3bd7d030e02/",
       "task_id"=>"a5874638-c6fe-4bf6-8962-b3bd7d030e02"}],
    "progress_report"=>
     {"yum_importer"=>
       {"content"=>
         {"items_total"=>0,
          "state"=>"FINISHED",
          "error_details"=>[],
          "details"=>
           {"rpm_total"=>0, "rpm_done"=>0, "drpm_total"=>0, "drpm_done"=>0},
          "size_total"=>0,
          "size_left"=>0,
          "items_left"=>0},
        "comps"=>{"state"=>"FINISHED"},
        "purge_duplicates"=>{"state"=>"FINISHED"},
        "distribution"=>
         {"items_total"=>0,
          "state"=>"FINISHED",
          "error_details"=>[],
          "items_left"=>0},
        "errata"=>{"state"=>"FINISHED"},
        "metadata"=>{"state"=>"FINISHED"}}},
    "queue"=>"reserved_resource_worker-0@hostname.dq",
    "state"=>"finished",
    "worker_name"=>"reserved_resource_worker-0@hostname",
    "result"=>
     {"result"=>"success",
      "importer_id"=>"yum_importer",
      "exception"=>nil,
      "repo_id"=>"d450d3ca-e3af-4099-bdee-05c33d5c3d0a",
      "traceback"=>nil,
      "started"=>"2018-08-13T07:45:19Z",
      "_ns"=>"repo_sync_results",
      "completed"=>"2018-08-13T07:52:31Z",
      "importer_type_id"=>"yum_importer",
      "error_message"=>nil,
      "summary"=>
       {"content"=>{"state"=>"FINISHED"},
        "comps"=>{"state"=>"FINISHED"},
        "purge_duplicates"=>{"state"=>"FINISHED"},
        "distribution"=>{"state"=>"FINISHED"},
        "errata"=>{"state"=>"FINISHED"},
        "metadata"=>{"state"=>"FINISHED"}},
      "added_count"=>0,
      "removed_count"=>0,
      "updated_count"=>1058,
      "id"=>"5b7138bf71f3b67c841952d9",
      "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"},
        "purge_duplicates"=>{"state"=>"FINISHED"},
        "distribution"=>
         {"items_total"=>0,
          "state"=>"FINISHED",
          "error_details"=>[],
          "items_left"=>0},
        "errata"=>{"state"=>"FINISHED"},
        "metadata"=>{"state"=>"FINISHED"}}},
    "error"=>nil,
    "_id"=>{"$oid"=>"5b71370f0b9f0f61d97dd10e"},
    "id"=>"5b71370f0b9f0f61d97dd10e"},
   {"exception"=>nil,
    "task_type"=>"pulp.server.managers.repo.publish.publish",
    "_href"=>"/pulp/api/v2/tasks/a5874638-c6fe-4bf6-8962-b3bd7d030e02/",
    "task_id"=>"a5874638-c6fe-4bf6-8962-b3bd7d030e02",
    "tags"=>
     ["pulp:repository:d450d3ca-e3af-4099-bdee-05c33d5c3d0a",
      "pulp:action:publish"],
    "finish_time"=>nil,
    "_ns"=>"task_status",
    "start_time"=>"2018-08-13T07:52:32Z",
    "traceback"=>nil,
    "spawned_tasks"=>[],
    "progress_report"=>
     {"d450d3ca-e3af-4099-bdee-05c33d5c3d0a"=>
       [{"num_success"=>1,
         "description"=>"Copying files",
         "step_type"=>"save_tar",
         "items_total"=>1,
         "state"=>"FINISHED",
         "error_details"=>[],
         "details"=>"",
         "num_failures"=>0,
         "step_id"=>"0cb5ee88-d634-4899-a076-d86d5a19bf8b",
         "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"=>"68d9374b-5bf8-4e97-92fe-23bfba5fb0b2",
         "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"=>"7a1a447c-d4a8-43aa-8c44-55c212c5d54a",
         "num_processed"=>0},
        {"num_success"=>2,
         "description"=>"Publishing RPMs",
         "step_type"=>"rpms",
         "items_total"=>65,
         "state"=>"IN_PROGRESS",
         "error_details"=>[],
         "details"=>"",
         "num_failures"=>0,
         "step_id"=>"3a81d3cb-4a31-4348-9943-9b7c77fecf08",
         "num_processed"=>2},
        {"num_success"=>0,
         "description"=>"Publishing Delta RPMs",
         "step_type"=>"drpms",
         "items_total"=>1,
         "state"=>"NOT_STARTED",
         "error_details"=>[],
         "details"=>"",
         "num_failures"=>0,
         "step_id"=>"a89307a1-3fd3-4701-991a-7db822fb408e",
         "num_processed"=>0},
        {"num_success"=>0,
         "description"=>"Publishing Errata",
         "step_type"=>"errata",
         "items_total"=>1,
         "state"=>"NOT_STARTED",
         "error_details"=>[],
         "details"=>"",
         "num_failures"=>0,
         "step_id"=>"817fcdc7-5961-4d05-8704-38a9ea45c4a6",
         "num_processed"=>0},
        {"num_success"=>0,
         "description"=>"Publishing Comps file",
         "step_type"=>"comps",
         "items_total"=>1,
         "state"=>"NOT_STARTED",
         "error_details"=>[],
         "details"=>"",
         "num_failures"=>0,
         "step_id"=>"a1abe816-8a95-45bf-a75a-0baf5577feeb",
         "num_processed"=>0},
        {"num_success"=>0,
         "description"=>"Publishing Metadata.",
         "step_type"=>"metadata",
         "items_total"=>1,
         "state"=>"NOT_STARTED",
         "error_details"=>[],
         "details"=>"",
         "num_failures"=>0,
         "step_id"=>"35e1208f-ccc6-446d-96bd-4f8e9884767b",
         "num_processed"=>0},
        {"num_success"=>0,
         "description"=>"Closing repo metadata",
         "step_type"=>"close_repo_metadata",
         "items_total"=>1,
         "state"=>"NOT_STARTED",
         "error_details"=>[],
         "details"=>"",
         "num_failures"=>0,
         "step_id"=>"93dd6b8c-3fc6-4b3d-b6e2-0c011459213c",
         "num_processed"=>0},
        {"num_success"=>0,
         "description"=>"Generating sqlite files",
         "step_type"=>"generate sqlite",
         "items_total"=>1,
         "state"=>"NOT_STARTED",
         "error_details"=>[],
         "details"=>"",
         "num_failures"=>0,
         "step_id"=>"eeacd310-b3b6-4b80-85f3-3d5dde07eaf8",
         "num_processed"=>0},
        {"num_success"=>0,
         "description"=>"Generating HTML files",
         "step_type"=>"repoview",
         "items_total"=>1,
         "state"=>"NOT_STARTED",
         "error_details"=>[],
         "details"=>"",
         "num_failures"=>0,
         "step_id"=>"c62aefda-c06a-4a72-a79c-7b076037cf33",
         "num_processed"=>0},
        {"num_success"=>0,
         "description"=>"Publishing files to web",
         "step_type"=>"publish_directory",
         "items_total"=>1,
         "state"=>"NOT_STARTED",
         "error_details"=>[],
         "details"=>"",
         "num_failures"=>0,
         "step_id"=>"f8993331-c57d-42c1-9e52-cf68cf5bdf6f",
         "num_processed"=>0},
        {"num_success"=>0,
         "description"=>"Writing Listings File",
         "step_type"=>"initialize_repo_metadata",
         "items_total"=>1,
         "state"=>"NOT_STARTED",
         "error_details"=>[],
         "details"=>"",
         "num_failures"=>0,
         "step_id"=>"3359969c-7945-4e76-8d78-6286cdcbb296",
         "num_processed"=>0},
        {"num_success"=>0,
         "description"=>"Writing Listings File",
         "step_type"=>"initialize_repo_metadata",
         "items_total"=>1,
         "state"=>"NOT_STARTED",
         "error_details"=>[],
         "details"=>"",
         "num_failures"=>0,
         "step_id"=>"bd1c79b8-627a-497c-8ac5-29274b332916",
         "num_processed"=>0}]},
    "queue"=>"reserved_resource_worker-0@hostname.dq",
    "state"=>"canceled",
    "worker_name"=>"reserved_resource_worker-0@hostname",
    "result"=>nil,
    "error"=>nil,
    "_id"=>{"$oid"=>"5b7138bf0b9f0f61d97dd111"},
    "id"=>"5b7138bf0b9f0f61d97dd111"}],
 "contents_changed"=>true,
 "poll_attempts"=>{"total"=>48, "failed"=>1}}
Exception:
Katello::Errors::PulpError: Task canceled
Backtrace:
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5/app/lib/actions/pulp/abstract_async_task.rb:121:in `block in external_task='
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5/app/lib/actions/pulp/abstract_async_task.rb:119:in `each'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5/app/lib/actions/pulp/abstract_async_task.rb:119:in `external_task='
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5/app/lib/actions/pulp/repository/sync.rb:48:in `external_task='
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/action/polling.rb:98:in `poll_external_task_with_rescue'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/action/polling.rb:21:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/action/cancellable.rb:13:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5/app/lib/actions/pulp/abstract_async_task.rb:45:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/action.rb:518:in `block (3 levels) in execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/middleware/stack.rb:26:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/middleware.rb:31:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5/app/lib/actions/middleware/remote_action.rb:16:in `block in run'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5/app/lib/actions/middleware/remote_action.rb:40:in `block in as_remote_user'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5/app/models/katello/concerns/user_extensions.rb:21:in `cp_config'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5/app/lib/actions/middleware/remote_action.rb:27:in `as_cp_user'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5/app/lib/actions/middleware/remote_action.rb:39:in `as_remote_user'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5/app/lib/actions/middleware/remote_action.rb:16:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/action/progress.rb:30:in `with_progress_calculation'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/action/progress.rb:16:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5/app/lib/actions/middleware/keep_locale.rb:11:in `block in run'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5/app/lib/actions/middleware/keep_locale.rb:22:in `with_locale'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.4.5/app/lib/actions/middleware/keep_locale.rb:11:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/middleware.rb:31:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/middleware/world.rb:30:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/action.rb:517:in `block (2 levels) in execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/action.rb:516:in `catch'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/action.rb:516:in `block in execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/action.rb:431:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/action.rb:431:in `block in with_error_handling'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/action.rb:431:in `catch'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/action.rb:431:in `with_error_handling'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/action.rb:511:in `execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/action.rb:268:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:9:in `block (2 levels) in execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/execution_plan/steps/abstract.rb:155:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/execution_plan/steps/abstract.rb:155:in `with_meta_calculation'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:8:in `block in execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:22:in `open_action'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:7:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/director.rb:55:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/executors/parallel/worker.rb:11:in `on_message'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/context.rb:46:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/executes_context.rb:7:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-0.8.34/lib/dynflow/actor.rb:26:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/awaits.rb:15:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/buffer.rb:38:in `process_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/buffer.rb:31:in `process_envelopes?'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/buffer.rb:20:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/termination.rb:55:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/removes_child.rb:10:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/core.rb:161:in `process_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/core.rb:95:in `block in on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/core.rb:118:in `block (2 levels) in schedule_execution'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/synchronization/mri_lockable_object.rb:38:in `block in synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/synchronization/mri_lockable_object.rb:38:in `synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/synchronization/mri_lockable_object.rb:38:in `synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.3/lib/concurrent/actor/core.rb:115:in `block in schedule_execution'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/serialized_execution.rb:18:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/serialized_execution.rb:18:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/serialized_execution.rb:96:in `work'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/serialized_execution.rb:77:in `block in call_job'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:348:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:348:in `run_task'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:337:in `block (3 levels) in create_worker'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:320:in `loop'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:320:in `block (2 levels) in create_worker'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:319:in `catch'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-1.0.3/lib/concurrent/executor/ruby_thread_pool_executor.rb:319:in `block in create_worker'
/opt/theforeman/tfm/root/usr/share/gems/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `block in create_with_logging_context'

Expected outcome:

Repo sync should complete.

Foreman and Proxy versions:

foreman-1.15.6

Foreman and Proxy plugin versions:

$ rpm -qa | grep -i foreman
tfm-rubygem-foreman-tasks-core-0.1.8-1.fm1_15.el7.noarch
foreman-proxy-1.15.6-1.el7.noarch
tfm-rubygem-hammer_cli_foreman_bootdisk-0.1.3-5.el7.noarch
hostname.domain.name-foreman-proxy-client-1.0-1.noarch
hostname.domain.name-foreman-client-1.0-1.noarch
tfm-rubygem-foreman_docker-3.2.1-1.fm1_15.el7.noarch
foreman-debug-1.15.6-1.el7.noarch
tfm-rubygem-hammer_cli_foreman_docker-0.0.4-2.el7.noarch
foreman-release-scl-3-1.el7.noarch
foreman-1.15.6-1.el7.noarch
tfm-rubygem-hammer_cli_foreman-0.10.2-1.el7.noarch
tfm-rubygem-foreman-tasks-0.9.6-1.fm1_15.el7.noarch
foreman-postgresql-1.15.6-1.el7.noarch
foreman-cli-1.15.6-1.el7.noarch
foreman-release-1.15.6-1.el7.noarch
foreman-compute-1.15.6-1.el7.noarch
foreman-installer-1.15.6-2.el7.noarch
tfm-rubygem-hammer_cli_foreman_tasks-0.0.12-1.fm1_15.el7.noarch
hostname.domain.name-foreman-proxy-1.0-1.noarch
foreman-selinux-1.15.6-1.el7.noarch
foreman-installer-katello-3.4.5-1.el7.noarch

$ rpm -qa | grep -i katello
tfm-rubygem-katello-3.4.5-1.el7.noarch
katello-selinux-3.0.2-1.el7.noarch
katello-3.4.5-1.el7.noarch
katello-repos-3.4.0-3.el7.noarch
katello-common-3.4.5-1.el7.noarch
katello-client-bootstrap-1.4.0-2.el7.noarch
tfm-rubygem-hammer_cli_katello-0.10.0-1.el7.noarch
katello-service-3.4.5-1.el7.noarch
katello-installer-base-3.4.5-1.el7.noarch
katello-server-ca-1.0-1.noarch
katello-certs-tools-2.4.0-1.el7.noarch
katello-default-ca-1.0-1.noarch
katello-debug-3.4.5-1.el7.noarch
foreman-installer-katello-3.4.5-1.el7.noarch
pulp-katello-1.0.2-1.el7.noarch

Other relevant data:
[e.g. logs from Foreman and/or the Proxy, modified templates, commands issued, etc]

Chris_Duryee · August 13, 2018, 11:22am

Is there any error in /var/log/messages? Depending on the Pulp version, you may be able to grep for d450d3ca to find errors related to the task.

Also, did an OOM event occur?

katello_user · August 13, 2018, 11:30am

No, there is no OOM event.

This is the result of the grep you wanted:

[root@hostname ~]# grep -i -A5 -B5 d450d3ca /var/log/messages
<SNIP>
Aug 12 19:17:51 hostname pulp: pulp_rpm.plugins.importers.yum.sync:INFO: [b24bc1da] Sync complete.
Aug 12 19:17:51 hostname pulp: py.warnings:WARNING: [b24bc1da] (93108-04064) /usr/lib/python2.7/site-packages/pulp/server/controllers/repository.py:817: DeprecationWarning: save is deprecated. Use insert_one or replace_one instead
Aug 12 19:17:51 hostname pulp: py.warnings:WARNING: [b24bc1da] (93108-04064)   sync_result_collection.save(sync_result)
Aug 12 19:17:51 hostname pulp: py.warnings:WARNING: [b24bc1da] (93108-04064)
Aug 12 19:17:51 hostname pulp: pulp.server.event.http:INFO: [b24bc1da] (93108-04064) {"call_report": {"exception": null, "task_type": "pulp.server.managers.repo.sync.sync", "_href": "/pulp/api/v2/tasks/b24bc1da-bbe4-4aff-a429-31c34902c0b6/", "task_id": "b24bc1da-bbe4-4aff-a429-31c34902c0b6", "tags": ["pulp:repository:d450d3ca-e3af-4099-bdee-05c33d5c3d0a", "pulp:action:sync"], "finish_time": null, "_ns": "task_status", "start_time": "2018-08-12T19:01:25Z", "traceback": null, "spawned_tasks": [], "progress_report": {"yum_importer": {"content": {"items_total": 64, "state": "FINISHED", "error_details": [], "details": {"rpm_total": 64, "rpm_done": 64, "drpm_total": 0, "drpm_done": 0}, "size_total": 1593021943, "size_left": 0, "items_left": 0}, "comps": {"state": "FINISHED"}, "purge_duplicates": {"state": "FINISHED"}, "distribution": {"items_total": 0, "state": "FINISHED", "error_details": [], "items_left": 0}, "errata": {"state": "FINISHED"}, "metadata": {"state": "FINISHED"}}}, "state": "running", "worker_name": "reserved_resource_worker-1@hostname", "result": null, "error": null, "_id": {"$oid": "5b7084050b9f0f61d97dcd5a"}, "id": "5b7084050b9f0f61d97dcd5a"}, "event_type": "repo.sync.finish", "payload": {"importer_id": "yum_importer", "exception": null, "repo_id": "d450d3ca-e3af-4099-bdee-05c33d5c3d0a", "traceback": null, "started": "2018-08-12T19:01:25Z", "_ns": "repo_sync_results", "completed": "2018-08-12T19:17:51Z", "importer_type_id": "yum_importer", "error_message": null, "summary": {"content": {"state": "FINISHED"}, "comps": {"state": "FINISHED"}, "purge_duplicates": {"state": "FINISHED"}, "distribution": {"state": "FINISHED"}, "errata": {"state": "FINISHED"}, "metadata": {"state": "FINISHED"}}, "added_count": 82, "result": "success", "updated_count": 1041, "details": {"content": {"size_total": 1593021943, "items_left": 0, "items_total": 64, "state": "FINISHED", "size_left": 0, "details": {"rpm_total": 64, "rpm_done": 64, "drpm_total": 0, "drpm_done": 0}, "error_details": []}, "comps": {"state": "FINISHED"}, "purge_duplica
Aug 12 19:17:51 hostname pulp: pulp.server.event.http:INFO: [b24bc1da] (93108-04064) tes": {"state": "FINISHED"}, "distribution": {"items_total": 0, "state": "FINISHED", "error_details": [], "items_left": 0}, "errata": {"state": "FINISHED"}, "metadata": {"state": "FINISHED"}}, "id": "5b7087df71f3b66bb57b1f10", "removed_count": 0}}
Aug 12 19:17:51 hostname pulp: requests.packages.urllib3.connectionpool:INFO: Starting new HTTPS connection (1): hostname.domain.name
Aug 12 19:17:51 hostname pulp: py.warnings:WARNING: (93108-04064) /usr/lib/python2.7/site-packages/pulp/server/db/model/__init__.py:552: DeprecationWarning: update is deprecated. Use replace_one, update_one or update_many instead.
Aug 12 19:17:51 hostname pulp: py.warnings:WARNING: (93108-04064)   TaskStatus._get_collection().update({'task_id': task_id}, update, upsert=True)
Aug 12 19:17:51 hostname pulp: py.warnings:WARNING: (93108-04064)
--
Aug 12 19:19:34 hostname pulp: py.warnings:WARNING: [f492e774] (102759-04064)   publish_result_coll.save(result)
Aug 12 19:19:34 hostname pulp: py.warnings:WARNING: [f492e774] (102759-04064)
Aug 12 19:19:34 hostname pulp: py.warnings:WARNING: [f492e774] (102759-04064) /usr/lib/python2.7/site-packages/mongoengine/document.py:367: DeprecationWarning: update is deprecated. Use replace_one, update_one or update_many instead.
Aug 12 19:19:34 hostname pulp: py.warnings:WARNING: [f492e774] (102759-04064)   upsert=upsert, **write_concern)
Aug 12 19:19:34 hostname pulp: py.warnings:WARNING: [f492e774] (102759-04064)
Aug 12 19:19:35 hostname pulp: celery.worker.job:INFO: Task pulp.server.managers.repo.publish.publish[f492e774-9296-4517-8d5f-89d7eddaa303] succeeded in 103.275257908s: {'exception': None, 'repo_id': u'd450d3ca-e3af-4099-bdee-05c33d5c3d0a', 'traceback': None, 'started': '2018-08-12T19:17:52Z',...
Aug 12 19:19:44 hostname agent: 2018-08-12 15:19:44 EDT | WARN | (datadog_agent.go:135 in LogMessage) | (disk.py:105) | Unable to get disk metrics for /sys/kernel/debug/tracing: [Errno 13] Permission denied: '/sys/kernel/debug/tracing'
Aug 12 19:19:49 hostname agent: 2018-08-12 15:19:49 EDT | INFO | (ntp.go:122 in Run) | There was an error querying the ntp host: read udp 10.201.132.38:56210->158.69.226.90:123: i/o timeout
Aug 12 19:19:59 hostname agent: 2018-08-12 15:19:59 EDT | WARN | (datadog_agent.go:135 in LogMessage) | (disk.py:105) | Unable to get disk metrics for /sys/kernel/debug/tracing: [Errno 13] Permission denied: '/sys/kernel/debug/tracing'
Aug 12 19:20:01 hostname systemd: Created slice User Slice of root.
Aug 12 19:20:01 hostname systemd: Starting User Slice of root.
--
Aug 12 19:43:19 hostname agent: 2018-08-12 15:43:19 EDT | INFO | (ntp.go:122 in Run) | There was an error querying the ntp host: read udp 10.201.132.38:28110->158.69.226.90:123: i/o timeout
Aug 12 19:43:24 hostname pulp: pulp_rpm.plugins.importers.yum.sync:INFO: [230f048b] Sync complete.
Aug 12 19:43:24 hostname pulp: py.warnings:WARNING: [230f048b] (107367-93920) /usr/lib/python2.7/site-packages/pulp/server/controllers/repository.py:817: DeprecationWarning: save is deprecated. Use insert_one or replace_one instead
Aug 12 19:43:24 hostname pulp: py.warnings:WARNING: [230f048b] (107367-93920)   sync_result_collection.save(sync_result)
Aug 12 19:43:24 hostname pulp: py.warnings:WARNING: [230f048b] (107367-93920)
Aug 12 19:43:24 hostname pulp: pulp.server.event.http:INFO: [230f048b] (107367-93920) {"call_report": {"exception": null, "task_type": "pulp.server.managers.repo.sync.sync", "_href": "/pulp/api/v2/tasks/230f048b-9dc4-4828-af62-fc31705970f4/", "task_id": "230f048b-9dc4-4828-af62-fc31705970f4", "tags": ["pulp:repository:d450d3ca-e3af-4099-bdee-05c33d5c3d0a", "pulp:action:sync"], "finish_time": null, "_ns": "task_status", "start_time": "2018-08-12T19:37:57Z", "traceback": null, "spawned_tasks": [], "progress_report": {"yum_importer": {"content": {"items_total": 0, "state": "FINISHED", "error_details": [], "details": {"rpm_total": 0, "rpm_done": 0, "drpm_total": 0, "drpm_done": 0}, "size_total": 0, "size_left": 0, "items_left": 0}, "comps": {"state": "FINISHED"}, "purge_duplicates": {"state": "FINISHED"}, "distribution": {"items_total": 0, "state": "FINISHED", "error_details": [], "items_left": 0}, "errata": {"state": "FINISHED"}, "metadata": {"state": "FINISHED"}}}, "state": "running", "worker_name": "reserved_resource_worker-0@hostname", "result": null, "error": null, "_id": {"$oid": "5b708c950b9f0f61d97dd0b1"}, "id": "5b708c950b9f0f61d97dd0b1"}, "event_type": "repo.sync.finish", "payload": {"importer_id": "yum_importer", "exception": null, "repo_id": "d450d3ca-e3af-4099-bdee-05c33d5c3d0a", "traceback": null, "started": "2018-08-12T19:37:57Z", "_ns": "repo_sync_results", "completed": "2018-08-12T19:43:24Z", "importer_type_id": "yum_importer", "error_message": null, "summary": {"content": {"state": "FINISHED"}, "comps": {"state": "FINISHED"}, "purge_duplicates": {"state": "FINISHED"}, "distribution": {"state": "FINISHED"}, "errata": {"state": "FINISHED"}, "metadata": {"state": "FINISHED"}}, "added_count": 0, "result": "success", "updated_count": 1058, "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"}, "purge_duplicates": {"state": "FINISHE
Aug 12 19:43:24 hostname pulp: pulp.server.event.http:INFO: [230f048b] (107367-93920) D"}, "distribution": {"items_total": 0, "state": "FINISHED", "error_details": [], "items_left": 0}, "errata": {"state": "FINISHED"}, "metadata": {"state": "FINISHED"}}, "id": "5b708ddc71f3b6a3681952d9", "removed_count": 0}}
Aug 12 19:43:24 hostname pulp: requests.packages.urllib3.connectionpool:INFO: Starting new HTTPS connection (1): hostname.domain.name
Aug 12 19:43:24 hostname pulp: celery.worker.strategy:INFO: Received task: pulp.server.async.tasks._queue_reserved_task[1db327ed-142d-499c-9aeb-78b165fdf6f1]
Aug 12 19:43:24 hostname pulp: celery.worker.strategy:INFO: Received task: pulp.server.managers.repo.publish.publish[e2dd592a-fd4e-4e00-aa35-7bc3bf8492eb]
Aug 12 19:43:24 hostname pulp: celery.worker.job:INFO: Task pulp.server.managers.repo.sync.sync[230f048b-9dc4-4828-af62-fc31705970f4] succeeded in 326.769191588s: <pulp.server.async.tasks.TaskResult object at 0x7f6bc9012a90>
--
Aug 12 19:45:01 hostname systemd: Starting Session 268623 of user root.
Aug 12 19:45:01 hostname systemd: Started Session 268624 of user root.
Aug 12 19:45:01 hostname systemd: Starting Session 268624 of user root.
Aug 12 19:45:01 hostname systemd: Removed slice User Slice of root.
Aug 12 19:45:01 hostname systemd: Stopping User Slice of root.
Aug 12 19:45:01 hostname pulp: celery.worker.job:INFO: Task pulp.server.managers.repo.publish.publish[e2dd592a-fd4e-4e00-aa35-7bc3bf8492eb] succeeded in 96.7564611854s: {'exception': None, 'repo_id': u'd450d3ca-e3af-4099-bdee-05c33d5c3d0a', 'traceback': None, 'started': '2018-08-12T19:43:24Z',...
Aug 12 19:45:01 hostname pulp: py.warnings:WARNING: [fe264d64] (115212-93920) /usr/lib64/python2.7/site-packages/pymongo/topology.py:74: UserWarning: MongoClient opened before fork. Create MongoClient with connect=False, or create client after forking. See PyMongo's documentation for details: http://api.mongodb.org/python/current/faq.html#using-pymongo-with-multiprocessing>
Aug 12 19:45:01 hostname pulp: py.warnings:WARNING: [fe264d64] (115212-93920)   "MongoClient opened before fork. Create MongoClient "
Aug 12 19:45:01 hostname pulp: py.warnings:WARNING: [fe264d64] (115212-93920)
Aug 12 19:45:01 hostname pulp: celery.worker.job:INFO: Task pulp.server.async.tasks._release_resource[fe264d64-7101-45ae-9dad-5ae71b7759ed] succeeded in 0.00849003251642s: None
Aug 12 19:45:04 hostname agent: 2018-08-12 15:45:04 EDT | INFO | (ntp.go:122 in Run) | There was an error querying the ntp host: read udp 10.201.132.38:24304->144.217.65.183:123: i/o timeout
--
Aug 13 07:52:29 hostname agent: 2018-08-13 03:52:29 EDT | WARN | (datadog_agent.go:135 in LogMessage) | (disk.py:105) | Unable to get disk metrics for /sys/kernel/debug/tracing: [Errno 13] Permission denied: '/sys/kernel/debug/tracing'
Aug 13 07:52:31 hostname pulp: pulp_rpm.plugins.importers.yum.sync:INFO: [f53c9015] Sync complete.
Aug 13 07:52:31 hostname pulp: py.warnings:WARNING: [f53c9015] (31876-93920) /usr/lib/python2.7/site-packages/pulp/server/controllers/repository.py:817: DeprecationWarning: save is deprecated. Use insert_one or replace_one instead
Aug 13 07:52:31 hostname pulp: py.warnings:WARNING: [f53c9015] (31876-93920)   sync_result_collection.save(sync_result)
Aug 13 07:52:31 hostname pulp: py.warnings:WARNING: [f53c9015] (31876-93920)
Aug 13 07:52:31 hostname pulp: pulp.server.event.http:INFO: [f53c9015] (31876-93920) {"call_report": {"exception": null, "task_type": "pulp.server.managers.repo.sync.sync", "_href": "/pulp/api/v2/tasks/f53c9015-ca56-45f6-b105-be97b09c23aa/", "task_id": "f53c9015-ca56-45f6-b105-be97b09c23aa", "tags": ["pulp:repository:d450d3ca-e3af-4099-bdee-05c33d5c3d0a", "pulp:action:sync"], "finish_time": null, "_ns": "task_status", "start_time": "2018-08-13T07:45:19Z", "traceback": null, "spawned_tasks": [], "progress_report": {"yum_importer": {"content": {"items_total": 0, "state": "FINISHED", "error_details": [], "details": {"rpm_total": 0, "rpm_done": 0, "drpm_total": 0, "drpm_done": 0}, "size_total": 0, "size_left": 0, "items_left": 0}, "comps": {"state": "FINISHED"}, "purge_duplicates": {"state": "FINISHED"}, "distribution": {"items_total": 0, "state": "FINISHED", "error_details": [], "items_left": 0}, "errata": {"state": "FINISHED"}, "metadata": {"state": "FINISHED"}}}, "state": "running", "worker_name": "reserved_resource_worker-0@hostname", "result": null, "error": null, "_id": {"$oid": "5b71370f0b9f0f61d97dd10e"}, "id": "5b71370f0b9f0f61d97dd10e"}, "event_type": "repo.sync.finish", "payload": {"importer_id": "yum_importer", "exception": null, "repo_id": "d450d3ca-e3af-4099-bdee-05c33d5c3d0a", "traceback": null, "started": "2018-08-13T07:45:19Z", "_ns": "repo_sync_results", "completed": "2018-08-13T07:52:31Z", "importer_type_id": "yum_importer", "error_message": null, "summary": {"content": {"state": "FINISHED"}, "comps": {"state": "FINISHED"}, "purge_duplicates": {"state": "FINISHED"}, "distribution": {"state": "FINISHED"}, "errata": {"state": "FINISHED"}, "metadata": {"state": "FINISHED"}}, "added_count": 0, "result": "success", "updated_count": 1058, "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"}, "purge_duplicates": {"state": "FINISHED
Aug 13 07:52:31 hostname pulp: pulp.server.event.http:INFO: [f53c9015] (31876-93920) "}, "distribution": {"items_total": 0, "state": "FINISHED", "error_details": [], "items_left": 0}, "errata": {"state": "FINISHED"}, "metadata": {"state": "FINISHED"}}, "id": "5b7138bf71f3b67c841952d9", "removed_count": 0}}
Aug 13 07:52:31 hostname pulp: requests.packages.urllib3.connectionpool:INFO: Starting new HTTPS connection (1): hostname.domain.name
Aug 13 07:52:31 hostname pulp: py.warnings:WARNING: (31876-93920) /usr/lib/python2.7/site-packages/pulp/server/db/model/__init__.py:552: DeprecationWarning: update is deprecated. Use replace_one, update_one or update_many instead.
Aug 13 07:52:31 hostname pulp: py.warnings:WARNING: (31876-93920)   TaskStatus._get_collection().update({'task_id': task_id}, update, upsert=True)
Aug 13 07:52:31 hostname pulp: py.warnings:WARNING: (31876-93920)
--
<SNIP>
Aug 13 07:54:14 hostname agent: 2018-08-13 03:54:14 EDT | WARN | (datadog_agent.go:135 in LogMessage) | (disk.py:105) | Unable to get disk metrics for /sys/kernel/debug/tracing: [Errno 13] Permission denied: '/sys/kernel/debug/tracing'
Aug 13 07:54:16 hostname pulp: py.warnings:WARNING: [a5874638] (35938-93920) /usr/lib/python2.7/site-packages/pulp/server/controllers/repository.py:1298: DeprecationWarning: save is deprecated. Use insert_one or replace_one instead
Aug 13 07:54:16 hostname pulp: py.warnings:WARNING: [a5874638] (35938-93920)   publish_result_coll.save(result)
Aug 13 07:54:16 hostname pulp: py.warnings:WARNING: [a5874638] (35938-93920)
Aug 13 07:54:17 hostname pulp: celery.worker.job:INFO: Task pulp.server.managers.repo.publish.publish[a5874638-c6fe-4bf6-8962-b3bd7d030e02] succeeded in 104.615663487s: {'exception': None, 'repo_id': u'd450d3ca-e3af-4099-bdee-05c33d5c3d0a', 'traceback': None, 'started': '2018-08-13T07:52:34Z',...
Aug 13 07:54:17 hostname pulp: py.warnings:WARNING: [f172ea65] (36685-93920) /usr/lib64/python2.7/site-packages/pymongo/topology.py:74: UserWarning: MongoClient opened before fork. Create MongoClient with connect=False, or create client after forking. See PyMongo's documentation for details: http://api.mongodb.org/python/current/faq.html#using-pymongo-with-multiprocessing>
Aug 13 07:54:17 hostname pulp: py.warnings:WARNING: [f172ea65] (36685-93920)   "MongoClient opened before fork. Create MongoClient "
Aug 13 07:54:17 hostname pulp: py.warnings:WARNING: [f172ea65] (36685-93920)
Aug 13 07:54:17 hostname pulp: celery.worker.job:INFO: Task pulp.server.async.tasks._release_resource[f172ea65-0965-47d2-a397-6b176bdbc358] succeeded in 0.01162335556s: None
<SNIP>
--
Aug 13 10:20:38 hostname pulp: pulp_rpm.plugins.importers.yum.sync:INFO: [a8d0e9d7] Sync complete.
Aug 13 10:20:38 hostname trace-agent: 2018-08-13 06:20:38 INFO (receiver.go:325) - no data received
Aug 13 10:20:39 hostname pulp: py.warnings:WARNING: [a8d0e9d7] (93586-93920) /usr/lib/python2.7/site-packages/pulp/server/controllers/repository.py:817: DeprecationWarning: save is deprecated. Use insert_one or replace_one instead
Aug 13 10:20:39 hostname pulp: py.warnings:WARNING: [a8d0e9d7] (93586-93920)   sync_result_collection.save(sync_result)
Aug 13 10:20:39 hostname pulp: py.warnings:WARNING: [a8d0e9d7] (93586-93920)
Aug 13 10:20:39 hostname pulp: pulp.server.event.http:INFO: [a8d0e9d7] (93586-93920) {"call_report": {"exception": null, "task_type": "pulp.server.managers.repo.sync.sync", "_href": "/pulp/api/v2/tasks/a8d0e9d7-7068-4e24-b22b-921fbad2968b/", "task_id": "a8d0e9d7-7068-4e24-b22b-921fbad2968b", "tags": ["pulp:repository:d450d3ca-e3af-4099-bdee-05c33d5c3d0a", "pulp:action:sync"], "finish_time": null, "_ns": "task_status", "start_time": "2018-08-13T10:15:00Z", "traceback": null, "spawned_tasks": [], "progress_report": {"yum_importer": {"content": {"items_total": 0, "state": "FINISHED", "error_details": [], "details": {"rpm_total": 0, "rpm_done": 0, "drpm_total": 0, "drpm_done": 0}, "size_total": 0, "size_left": 0, "items_left": 0}, "comps": {"state": "FINISHED"}, "purge_duplicates": {"state": "FINISHED"}, "distribution": {"items_total": 0, "state": "FINISHED", "error_details": [], "items_left": 0}, "errata": {"state": "FINISHED"}, "metadata": {"state": "FINISHED"}}}, "state": "running", "worker_name": "reserved_resource_worker-0@hostname", "result": null, "error": null, "_id": {"$oid": "5b715a240b9f0f61d97dd120"}, "id": "5b715a240b9f0f61d97dd120"}, "event_type": "repo.sync.finish", "payload": {"importer_id": "yum_importer", "exception": null, "repo_id": "d450d3ca-e3af-4099-bdee-05c33d5c3d0a", "traceback": null, "started": "2018-08-13T10:15:00Z", "_ns": "repo_sync_results", "completed": "2018-08-13T10:20:38Z", "importer_type_id": "yum_importer", "error_message": null, "summary": {"content": {"state": "FINISHED"}, "comps": {"state": "FINISHED"}, "purge_duplicates": {"state": "FINISHED"}, "distribution": {"state": "FINISHED"}, "errata": {"state": "FINISHED"}, "metadata": {"state": "FINISHED"}}, "added_count": 0, "result": "success", "updated_count": 1058, "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"}, "purge_duplicates": {"state": "FINISHED
Aug 13 10:20:39 hostname pulp: pulp.server.event.http:INFO: [a8d0e9d7] (93586-93920) "}, "distribution": {"items_total": 0, "state": "FINISHED", "error_details": [], "items_left": 0}, "errata": {"state": "FINISHED"}, "metadata": {"state": "FINISHED"}}, "id": "5b715b7671f3b66d931952d9", "removed_count": 0}}
Aug 13 10:20:39 hostname pulp: requests.packages.urllib3.connectionpool:INFO: Starting new HTTPS connection (1): hostname.domain.name
Aug 13 10:20:39 hostname pulp: py.warnings:WARNING: (93586-93920) /usr/lib/python2.7/site-packages/pulp/server/db/model/__init__.py:552: DeprecationWarning: update is deprecated. Use replace_one, update_one or update_many instead.
Aug 13 10:20:39 hostname pulp: py.warnings:WARNING: (93586-93920)   TaskStatus._get_collection().update({'task_id': task_id}, update, upsert=True)
Aug 13 10:20:39 hostname pulp: py.warnings:WARNING: (93586-93920)
--
Aug 13 10:22:17 hostname pulp: py.warnings:WARNING: [ea6a516f] (99267-93920)   publish_result_coll.save(result)
Aug 13 10:22:17 hostname pulp: py.warnings:WARNING: [ea6a516f] (99267-93920)
Aug 13 10:22:17 hostname pulp: py.warnings:WARNING: [ea6a516f] (99267-93920) /usr/lib/python2.7/site-packages/mongoengine/document.py:367: DeprecationWarning: update is deprecated. Use replace_one, update_one or update_many instead.
Aug 13 10:22:17 hostname pulp: py.warnings:WARNING: [ea6a516f] (99267-93920)   upsert=upsert, **write_concern)
Aug 13 10:22:17 hostname pulp: py.warnings:WARNING: [ea6a516f] (99267-93920)
Aug 13 10:22:18 hostname pulp: celery.worker.job:INFO: Task pulp.server.managers.repo.publish.publish[ea6a516f-01ac-4f74-a84b-0716c1d56725] succeeded in 98.4157146476s: {'exception': None, 'repo_id': u'd450d3ca-e3af-4099-bdee-05c33d5c3d0a', 'traceback': None, 'started': '2018-08-13T10:20:40Z',...
Aug 13 10:22:18 hostname pulp: celery.worker.job:INFO: Task pulp.server.async.tasks._release_resource[caa28a64-cd20-4b3b-b4db-0e3b4566ecca] succeeded in 0.00969508010894s: None
<SNIP>
Aug 13 10:22:28 hostname trace-agent: 2018-08-13 06:22:28 INFO (service_mapper.go:59) - total number of tracked services: 0
Aug 13 10:22:29 hostname agent: 2018-08-13 06:22:29 EDT | WARN | (datadog_agent.go:135 in LogMessage) | (disk.py:105) | Unable to get disk metrics for /sys/kernel/debug/tracing: [Errno 13] Permission denied: '/sys/kernel/debug/tracing'
<SNIP>
[root@hostname ~]#

EDIT: Surprisingly I don’t see any error in the log messages.

Chris_Duryee · August 13, 2018, 11:59am

agreed, that is odd. Can you check if pulp_resource_manager, pulp_workers or pulp_celerybeat were restarted during the sync, and that they are currently running OK? If you do systemctl status X it should show the current status.

katello_user · August 13, 2018, 1:06pm

@Chris_Duryee looks like you are correct. The pulp_worker services are disappearing. Any idea why?

# systemctl -l | grep -i pulp
  var-lib-pulp.mount                                                                                                         loaded active mounted   /var/lib/pulp
  pulp_celerybeat.service                                                                                                    loaded active running   Pulp's Celerybeat
  pulp_resource_manager.service                                                                                              loaded active running   Pulp Resource Manager
  pulp_streamer.service                                                                                                      loaded active running   The Pulp lazy content loading streamer
  pulp_worker-0.service                                                                                                      loaded active running   Pulp Worker #0
  pulp_worker-1.service                                                                                                      loaded active running   Pulp Worker #1
  pulp_worker-2.service                                                                                                      loaded active running   Pulp Worker #2
  pulp_worker-3.service                                                                                                      loaded active running   Pulp Worker #3
  pulp_workers.service                                                                                                       loaded active exited    Pulp Celery Workers

Also when I checked the logs, I see this:

# journalctl -l -u pulp_celerybeat.service --since "1 hour ago"
-- Logs begin at Sun 2018-07-08 17:50:44 EDT, end at Mon 2018-08-13 09:04:04 EDT. --
Aug 13 08:13:24 hostname pulp[902]: celery.beat:INFO: Scheduler: Sending due task download_deferred_content (pulp.server.controll
Aug 13 08:23:24 hostname pulp[902]: celery.beat:INFO: Scheduler: Sending due task download_deferred_content (pulp.server.controll
Aug 13 08:33:24 hostname pulp[902]: celery.beat:INFO: Scheduler: Sending due task download_deferred_content (pulp.server.controll
Aug 13 08:43:24 hostname pulp[902]: celery.beat:INFO: Scheduler: Sending due task download_deferred_content (pulp.server.controll
Aug 13 08:53:24 hostname pulp[902]: celery.beat:INFO: Scheduler: Sending due task download_deferred_content (pulp.server.controll
Aug 13 09:00:42 hostname pulp[902]: pulp.server.async.scheduler:ERROR: Worker 'resource_manager@hostname' has gone missing,
Aug 13 09:00:42 hostname pulp[902]: pulp.server.async.tasks:ERROR: The worker named resource_manager@hostname is missing. Ca
Aug 13 09:00:42 hostname pulp[902]: pulp.server.async.scheduler:ERROR: Worker 'reserved_resource_worker-0@hostname' has gone
Aug 13 09:00:42 hostname pulp[902]: pulp.server.async.tasks:ERROR: The worker named reserved_resource_worker-0@hostname is m
Aug 13 09:00:42 hostname pulp[902]: kombu.transport.qpid:INFO: Connected to qpid with SASL mechanism ANONYMOUS
Aug 13 09:00:42 hostname pulp[902]: pulp.server.async.tasks:INFO: Task canceled: ef9410ee-38cd-49b0-bdd5-231463f89c09.
Aug 13 09:00:42 hostname pulp[902]: pulp.server.async.scheduler:ERROR: Worker 'scheduler@hostname' has gone missing, removin
Aug 13 09:00:42 hostname pulp[902]: pulp.server.async.scheduler:ERROR: Worker 'reserved_resource_worker-1@hostname' has gone
Aug 13 09:00:42 hostname pulp[902]: pulp.server.async.tasks:ERROR: The worker named reserved_resource_worker-1@hostname is m
Aug 13 09:00:42 hostname pulp[902]: pulp.server.async.scheduler:ERROR: Worker 'reserved_resource_worker-3@hostname' has gone
Aug 13 09:00:42 hostname pulp[902]: pulp.server.async.tasks:ERROR: The worker named reserved_resource_worker-3@hostname is m
Aug 13 09:00:42 hostname pulp[902]: pulp.server.async.scheduler:ERROR: Worker 'reserved_resource_worker-2@hostname' has gone
Aug 13 09:00:42 hostname pulp[902]: pulp.server.async.tasks:ERROR: The worker named reserved_resource_worker-2@hostname is m
Aug 13 09:00:42 hostname pulp[902]: pulp.server.async.scheduler:ERROR: There are 0 pulp_resource_manager processes running. Pulp
Aug 13 09:00:42 hostname pulp[902]: pulp.server.async.scheduler:ERROR: There are 0 pulp_celerybeat processes running. Pulp will n
Aug 13 09:00:47 hostname pulp[902]: pulp.server.async.worker_watcher:INFO: New worker 'scheduler@hostname' discovered
Aug 13 09:03:24 hostname pulp[902]: celery.beat:INFO: Scheduler: Sending due task download_deferred_content (pulp.server.controll
[root@hostname ~]#

Chris_Duryee · August 13, 2018, 4:11pm

You may be hitting Bug #22338: Workers go missing under heavy load - Katello - Foreman.

I would recommend upgrading to the latest released version, which will pull in that fix.

katello_user · August 13, 2018, 6:07pm

Thank you. I have to get authorization to do that, for now I will follow the workaround

Thanks again Chris.