Hi,
Problem:
Since upgrade TFM to 3.18 and Katello 3.7 i’m having trouble syncing some repositories:
For ex:
- Red Hat Enterprise Linux 7 Server - Optional RPMs x86_64 7.4 returns error: PLP0000: invalid length or type code
- EPEL 7 - x86_64 returns error: PLP0000: Importer indicated a failed response
The upgrade from TFM 1.17.1 & Katello 3.6 did run without problems.
Expected outcome:
Syncing repos without errors as before when using Katello 3.6
Foreman and Proxy versions:
foreman-1.18.0-2.el7.noarch
foreman-proxy-1.18.0-1.el7.noarch
Foreman and Proxy plugin versions:
katello-3.7.0-4.el7.noarch
Other relevant data:
[e.g. logs from Foreman and/or the Proxy, modified templates, commands issued, etc]
Log extract
Response: 200: {"exception": null, "task_type": "pulp.server.managers.repo.sync.sync", "_href": "/pulp/api/v2/tasks/8fd59285-b8d8-48f3-a519-427ca656ac1d/", "task_id": "8fd59285-b8d8-48f3-a519-427ca656ac1d", "tags": ["pulp:repository:e5ea2d9a-2661-4adb-85b1-cfdee667169f", "pulp:action:sync"], "finish_time": "2018-07-31T09:09:27Z", "_ns": "task_status", "start_time": "2018-07-31T09:05:02Z", "traceback": "Traceback (most recent call last):\n File \"/usr/lib/python2.7/site-packages/celery/app/trace.py\", line 367, in trace_task\n R = retval = fun(*args, **kwargs)\n File \"/usr/lib/python2.7/site-packages/pulp/server/async/tasks.py\", line 529, in __call__\n return super(Task, self).__call__(*args, **kwargs)\n File \"/usr/lib/python2.7/site-packages/pulp/server/async/tasks.py\", line 107, in __call__\n return super(PulpTask, self).__call__(*args, **kwargs)\n File \"/usr/lib/python2.7/site-packages/celery/app/trace.py\", line 622, in __protected_call__\n return self.run(*args, **kwargs)\n File \"/usr/lib/python2.7/site-packages/pulp/server/controllers/repository.py\", line 827, in sync\n raise pulp_exceptions.PulpExecutionException(_('Importer indicated a failed response'))\nPulpExecutionException: Importer indicated a failed response\n", "spawned_tasks": [], "progress_report": {"yum_importer": {"content": {"size_total": 0, "items_left": 0, "items_total": 0, "state": "FAILED", "size_left": 0, "details": {"rpm_total": 0, "rpm_done": 0, "drpm_total": 0, "drpm_done": 0}, "error": "BSONElement: bad type 99", "error_details": []}, "comps": {"state": "NOT_STARTED"}, "purge_duplicates": {"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-0@spfy-tfm.xxxx.xxxx.xxx.dq2", "state": "error", "worker_name": "reserved_resource_worker-0@spfy-tfm.xxxx.xxxx.xxxx", "result": null, "error": {"code": "PLP0000", "data": {}, "description": "Importer indicated a failed response", "sub_errors": []}, "_id": {"$oid": "5b60263e7267bcf978e31731"}, "id": "5b60263e7267bcf978e31731"}
2018-07-31T11:09:41 [app] [D] Setting current user thread-local variable to nil
2018-07-31T11:09:41 [background] [E] PLP0000: Importer indicated a failed response (Katello::Errors::PulpError)
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/pulp/abstract_async_task.rb:121:in `block in external_task='
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/pulp/abstract_async_task.rb:119:in `each'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/pulp/abstract_async_task.rb:119:in `external_task='
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/pulp/repository/sync.rb:48:in `external_task='
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/action/polling.rb:98:in `poll_external_task_with_rescue'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/action/polling.rb:21:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/action/cancellable.rb:13:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/pulp/abstract_async_task.rb:45:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/action.rb:538:in `block (3 levels) in execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/middleware.rb:31:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/middleware/remote_action.rb:16:in `block in run'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/middleware/remote_action.rb:40:in `block in as_remote_user'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/models/katello/concerns/user_extensions.rb:21:in `cp_config'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/middleware/remote_action.rb:27:in `as_cp_user'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/middleware/remote_action.rb:39:in `as_remote_user'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/middleware/remote_action.rb:16:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.13.2/app/lib/actions/middleware/rails_executor_wrap.rb:14:in `block in run'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/activesupport-5.1.6/lib/active_support/execution_wrapper.rb:85:in `wrap'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.13.2/app/lib/actions/middleware/rails_executor_wrap.rb:13:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/action/progress.rb:30:in `with_progress_calculation'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/action/progress.rb:16:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/middleware/keep_locale.rb:11:in `block in run'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/middleware/keep_locale.rb:22:in `with_locale'
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.7.0/app/lib/actions/middleware/keep_locale.rb:11:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.13.2/app/lib/actions/middleware/keep_current_user.rb:15:in `block in run'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.13.2/app/lib/actions/middleware/keep_current_user.rb:43:in `restore_curent_user'
/opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-0.13.2/app/lib/actions/middleware/keep_current_user.rb:15:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/middleware/stack.rb:26:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/middleware.rb:18:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/middleware.rb:31:in `run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/middleware/stack.rb:22:in `call'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/middleware/world.rb:30:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/action.rb:537:in `block (2 levels) in execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/action.rb:536:in `catch'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/action.rb:536:in `block in execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/action.rb:451:in `block in with_error_handling'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/action.rb:451:in `catch'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/action.rb:451:in `with_error_handling'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/action.rb:531:in `execute_run'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/action.rb:278:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:17:in `block (2 levels) in execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/execution_plan/steps/abstract.rb:162:in `with_meta_calculation'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:16:in `block in execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:30:in `open_action'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:15:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/director.rb:56:in `execute'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/executors/parallel/worker.rb:12:in `block in on_message'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/executors.rb:12:in `run_user_code'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/executors/parallel/worker.rb:11:in `on_message'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/context.rb:46:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/executes_context.rb:7:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.0.5/lib/dynflow/actor.rb:26:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/awaits.rb:15:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/buffer.rb:38:in `process_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/buffer.rb:31:in `process_envelopes?'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/buffer.rb:20:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/termination.rb:55:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/removes_child.rb:10:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/abstract.rb:25:in `pass'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/behaviour/sets_results.rb:14:in `on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/core.rb:161:in `process_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/core.rb:95:in `block in on_envelope'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/core.rb:118:in `block (2 levels) in schedule_execution'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/synchronization/mri_lockable_object.rb:38:in `block in synchronize'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/synchronization/mri_lockable_object.rb:38:in `synchronize'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/synchronization/mri_lockable_object.rb:38:in `synchronize'
/opt/theforeman/tfm/root/usr/share/gems/gems/concurrent-ruby-edge-0.2.4/lib/concurrent/actor/core.rb:115:in `block in schedule_execution'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/serialized_execution.rb:18:in `call'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/serialized_execution.rb:96:in `work'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/serialized_execution.rb:77:in `block in call_job'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:348:in `run_task'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:337:in `block (3 levels) in create_worker'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:320:in `loop'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:320:in `block (2 levels) in create_worker'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:319:in `catch'
/opt/theforeman/tfm-ror51/root/usr/share/gems/gems/concurrent-ruby-1.0.5/lib/concurrent/executor/ruby_thread_pool_executor.rb:319:in `block in create_worker'
/opt/theforeman/tfm/root/usr/share/gems/gems/logging-2.2.2/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'
It seems this is a pulp issue, i’ve already tried Bug #24443: 3.6 -> 3.7 upgrade on proxy does not always migrate pulp db - Katello - Foreman but it didn’t help.
Any idea or help how to debug that problem?
Thanks,
Arsene