"Remove orphans" task fails to complete 4.1.3 + 4.2.0rc1

Problem:
“Remove orphans” task fails every time it tries to run.

Expected outcome:
Cleaning up orphaned content without failing.

Foreman and Proxy versions:
foreman-3.0.0-1.el8.noarch
foreman-proxy-3.0.0-1.el8.noarch

Foreman and Proxy plugin versions:
katello-4.2.0.rc1-1.el8.noarch

Distribution and version:
CentOS 8.4

Other relevant data:

  • Error in task info

Error message: the server returns an error
HTTP status code: 500
Response headers: {"Date"=>"Sat, 25 Sep 2021 11:45:28 GMT", "Server"=>"gunicorn", "Content-Type"=>"text/html; charset=UTF-8", "X-Frame-Options"=>"SAMEORIGIN", "Content-Length"=>"27", "Vary"=>"Cookie", "Correlation-ID"=>"1bb5820524a84493aa33ce87ec695969", "Access-Control-Expose-Headers"=>"Correlation-ID", "Via"=>"1.1 XXX", "Connection"=>"close"}
Response body: <h1>Server Error (500)</h1>

  • Snippet from production.log
2021-09-25T13:45:22 [I|bac|] Task {label: Actions::Katello::OrphanCleanup::RemoveOrphans, id: beb4090f-025d-438f-be10-72b2e3cd8aad, execution_plan_id: b00c8995-1f42-4df3-bde5-c6bafa21f0d2} state changed: running 
2021-09-25T13:45:28 [E|bac|] Error message: the server returns an error
 | HTTP status code: 500
 | Response headers: {"Date"=>"Sat, 25 Sep 2021 11:45:28 GMT", "Server"=>"gunicorn", "Content-Type"=>"text/html; charset=UTF-8", "X-Frame-Options"=>"SAMEORIGIN", "Content-Length"=>"27", "Vary"=>"Cookie", "Correlation-ID"=>"1bb5820524a84493aa33ce87ec695969", "Access-Control-Expose-Headers"=>"Correlation-ID", "Via"=>"1.1 XXX", "Connection"=>"close"}
 | Response body: <h1>Server Error (500)</h1> (PulpRpmClient::ApiError)
 | /usr/share/gems/gems/pulp_rpm_client-3.13.3/lib/pulp_rpm_client/api_client.rb:83:in `call_api'
 | /usr/share/gems/gems/pulp_rpm_client-3.13.3/lib/pulp_rpm_client/api/repositories_rpm_versions_api.rb:196:in `list_with_http_info'
 | /usr/share/gems/gems/pulp_rpm_client-3.13.3/lib/pulp_rpm_client/api/repositories_rpm_versions_api.rb:109:in `list'
 | /usr/share/gems/gems/katello-4.2.0.rc1/app/services/katello/pulp3/api/core.rb:169:in `block in versions_list_for_repository'
 | /usr/share/gems/gems/katello-4.2.0.rc1/app/services/katello/pulp3/api/core.rb:214:in `block in fetch_from_list'
 | /usr/share/gems/gems/katello-4.2.0.rc1/app/services/katello/pulp3/api/core.rb:209:in `loop'
 | /usr/share/gems/gems/katello-4.2.0.rc1/app/services/katello/pulp3/api/core.rb:209:in `fetch_from_list'
 | /usr/share/gems/gems/katello-4.2.0.rc1/app/services/katello/pulp3/api/core.rb:169:in `versions_list_for_repository'
 | /usr/share/gems/gems/katello-4.2.0.rc1/app/services/katello/pulp3/api/core.rb:162:in `block in repository_versions'
 | /usr/share/gems/gems/katello-4.2.0.rc1/app/services/katello/pulp3/api/core.rb:161:in `collect'
 | /usr/share/gems/gems/katello-4.2.0.rc1/app/services/katello/pulp3/api/core.rb:161:in `repository_versions'
 | /usr/share/gems/gems/katello-4.2.0.rc1/app/services/katello/pulp3/smart_proxy_repository.rb:59:in `block in orphan_repository_versions'
 | /usr/share/gems/gems/katello-4.2.0.rc1/app/services/katello/pulp3/smart_proxy_repository.rb:57:in `each'
 | /usr/share/gems/gems/katello-4.2.0.rc1/app/services/katello/pulp3/smart_proxy_repository.rb:57:in `orphan_repository_versions'
 | /usr/share/gems/gems/katello-4.2.0.rc1/app/services/katello/pulp3/smart_proxy_repository.rb:39:in `delete_orphan_repository_versions'
 | /usr/share/gems/gems/katello-4.2.0.rc1/app/lib/actions/pulp3/orphan_cleanup/delete_orphan_repository_versions.rb:10:in `run'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/action.rb:572:in `block (3 levels) in execute_run'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware/stack.rb:27:in `pass'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware.rb:19:in `pass'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware.rb:32:in `run'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware/stack.rb:23:in `call'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware/stack.rb:27:in `pass'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware.rb:19:in `pass'
 | /usr/share/gems/gems/katello-4.2.0.rc1/app/lib/actions/middleware/remote_action.rb:16:in `block in run'
 | /usr/share/gems/gems/katello-4.2.0.rc1/app/lib/actions/middleware/remote_action.rb:40:in `block in as_remote_user'
 | /usr/share/gems/gems/katello-4.2.0.rc1/app/models/katello/concerns/user_extensions.rb:21:in `cp_config'
 | /usr/share/gems/gems/katello-4.2.0.rc1/app/lib/actions/middleware/remote_action.rb:27:in `as_cp_user'
 | /usr/share/gems/gems/katello-4.2.0.rc1/app/lib/actions/middleware/remote_action.rb:39:in `as_remote_user'
 | /usr/share/gems/gems/katello-4.2.0.rc1/app/lib/actions/middleware/remote_action.rb:16:in `run'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware/stack.rb:23:in `call'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware/stack.rb:27:in `pass'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware.rb:19:in `pass'
 | /usr/share/gems/gems/foreman-tasks-5.1.0/app/lib/actions/middleware/rails_executor_wrap.rb:14:in `block in run'
 | /usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/execution_wrapper.rb:88:in `wrap'
 | /usr/share/gems/gems/foreman-tasks-5.1.0/app/lib/actions/middleware/rails_executor_wrap.rb:13:in `run'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware/stack.rb:23:in `call'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware/stack.rb:27:in `pass'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware.rb:19:in `pass'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/action/progress.rb:31:in `with_progress_calculation'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/action/progress.rb:17:in `run'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware/stack.rb:23:in `call'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware/stack.rb:27:in `pass'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware.rb:19:in `pass'
 | /usr/share/gems/gems/foreman-tasks-5.1.0/app/lib/actions/middleware/load_setting_values.rb:20:in `run'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware/stack.rb:23:in `call'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware/stack.rb:27:in `pass'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware.rb:19:in `pass'
 | /usr/share/gems/gems/foreman-tasks-5.1.0/app/lib/actions/middleware/keep_current_request_id.rb:15:in `block in run'
 | /usr/share/gems/gems/foreman-tasks-5.1.0/app/lib/actions/middleware/keep_current_request_id.rb:52:in `restore_current_request_id'
 | /usr/share/gems/gems/foreman-tasks-5.1.0/app/lib/actions/middleware/keep_current_request_id.rb:15:in `run'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware/stack.rb:23:in `call'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware/stack.rb:27:in `pass'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware.rb:19:in `pass'
 | /usr/share/gems/gems/foreman-tasks-5.1.0/app/lib/actions/middleware/keep_current_timezone.rb:15:in `block in run'
 | /usr/share/gems/gems/foreman-tasks-5.1.0/app/lib/actions/middleware/keep_current_timezone.rb:44:in `restore_curent_timezone'
 | /usr/share/gems/gems/foreman-tasks-5.1.0/app/lib/actions/middleware/keep_current_timezone.rb:15:in `run'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware/stack.rb:23:in `call'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware/stack.rb:27:in `pass'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware.rb:19:in `pass'
 | /usr/share/gems/gems/foreman-tasks-5.1.0/app/lib/actions/middleware/keep_current_taxonomies.rb:15:in `block in run'
 | /usr/share/gems/gems/foreman-tasks-5.1.0/app/lib/actions/middleware/keep_current_taxonomies.rb:45:in `restore_current_taxonomies'
 | /usr/share/gems/gems/foreman-tasks-5.1.0/app/lib/actions/middleware/keep_current_taxonomies.rb:15:in `run'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware/stack.rb:23:in `call'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware/stack.rb:27:in `pass'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware.rb:19:in `pass'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware.rb:32:in `run'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware/stack.rb:23:in `call'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware/stack.rb:27:in `pass'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware.rb:19:in `pass'
 | /usr/share/gems/gems/foreman-tasks-5.1.0/app/lib/actions/middleware/keep_current_user.rb:15:in `block in run'
 | /usr/share/gems/gems/foreman-tasks-5.1.0/app/lib/actions/middleware/keep_current_user.rb:54:in `restore_curent_user'
 | /usr/share/gems/gems/foreman-tasks-5.1.0/app/lib/actions/middleware/keep_current_user.rb:15:in `run'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware/stack.rb:23:in `call'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/middleware/world.rb:31:in `execute'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/action.rb:571:in `block (2 levels) in execute_run'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/action.rb:570:in `catch'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/action.rb:570:in `block in execute_run'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/action.rb:473:in `block in with_error_handling'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/action.rb:473:in `catch'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/action.rb:473:in `with_error_handling'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/action.rb:565:in `execute_run'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/action.rb:286:in `execute'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:18:in `block (2 levels) in execute'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/execution_plan/steps/abstract.rb:167:in `with_meta_calculation'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:17:in `block in execute'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:32:in `open_action'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:16:in `execute'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/director.rb:69:in `execute'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/executors/sidekiq/worker_jobs.rb:11:in `block (2 levels) in perform'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/executors.rb:18:in `run_user_code'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/executors/sidekiq/worker_jobs.rb:9:in `block in perform'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/executors/sidekiq/worker_jobs.rb:25:in `with_telemetry'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/executors/sidekiq/worker_jobs.rb:8:in `perform'
 | /usr/share/gems/gems/dynflow-1.5.0/lib/dynflow/executors/sidekiq/serialization.rb:27:in `perform'

I cant remember if this ever worked, i see “Orphan remove” failing over several foreman/katello versions. This installation started with 2.5.0/4.1.0 trough all versions and today i updated to foreman 3.0 and katello 4.2.0rc1. This task is still failing. I read a bit about pulp and try to to this with pulp-cli and it succeded, but i am not sure if i supposed to do it this way.

i ran “pulp --base-url https://XXX/pulp/ --cert /etc/pki/katello/certs/pulp-client.crt --key /etc/pki/katello/private/pulp-client.key” and it finished with

Started background task /pulp/api/v3/tasks/f0cbfc68-6627-45fd-bde7-0c01f4e8eb56/
.......Done.
{
  "pulp_href": "/pulp/api/v3/tasks/f0cbfc68-6627-45fd-bde7-0c01f4e8eb56/",
  "pulp_created": "2021-09-25T12:03:42.147936Z",
  "state": "completed",
  "name": "pulpcore.app.tasks.orphan.orphan_cleanup",
  "logging_cid": "538a2780f00f4d39a559dac96dea4735",
  "started_at": "2021-09-25T12:03:42.267401Z",
  "finished_at": "2021-09-25T12:03:49.021088Z",
  "error": null,
  "worker": "/pulp/api/v3/workers/72c0069f-01be-4bb1-8f79-a88717512486/",
  "parent_task": null,
  "child_tasks": [],
  "task_group": null,
  "progress_reports": [
    {
      "message": "Clean up orphan Content",
      "code": "clean-up.content",
      "state": "completed",
      "total": 181,
      "done": 181,
      "suffix": null
    },
    {
      "message": "Clean up orphan Artifacts",
      "code": "clean-up.content",
      "state": "completed",
      "total": 582,
      "done": 582,
      "suffix": null
    }
  ],
  "created_resources": [],
  "reserved_resources_record": []
}

After this manual run with pulp-cli, the foreman task still fails if i try to run “Remove orphan” again.

Can you check the pulpcore-api logs? journalctl -u pulpcore-api to see what is triggering that 500 ISE in pulp?

Hi Justin,

this is all i get after executing this task (i am on version 4.2rc3 now):

Sep 30 17:11:21 xxx pulpcore-api[244250]: pulp [e9c240744ab9495589cb7b252f7f91df]: django.request:ERROR: Internal Server Error: /pulp/api/v3/repositories/rpm/rpm/8e8e0a36-93a5-4d38-b9be-cdfeee4cc951/versions/
Sep 30 17:11:21 xxx pulpcore-api[244250]: Traceback (most recent call last):
Sep 30 17:11:21 xxx pulpcore-api[244250]:   File "/usr/lib/python3.6/site-packages/django/core/handlers/exception.py", line 34, in inner
Sep 30 17:11:21 xxx pulpcore-api[244250]:     response = get_response(request)
Sep 30 17:11:21 xxx pulpcore-api[244250]:   File "/usr/lib/python3.6/site-packages/django/core/handlers/base.py", line 115, in _get_response
Sep 30 17:11:21 xxx pulpcore-api[244250]:     response = self.process_exception_by_middleware(e, request)
Sep 30 17:11:21 xxx pulpcore-api[244250]:   File "/usr/lib/python3.6/site-packages/django/core/handlers/base.py", line 113, in _get_response
Sep 30 17:11:21 xxx pulpcore-api[244250]:     response = wrapped_callback(request, *callback_args, **callback_kwargs)
Sep 30 17:11:21 xxx pulpcore-api[244250]:   File "/usr/lib/python3.6/site-packages/django/views/decorators/csrf.py", line 54, in wrapped_view
Sep 30 17:11:21 xxx pulpcore-api[244250]:     return view_func(*args, **kwargs)
Sep 30 17:11:21 xxx pulpcore-api[244250]:   File "/usr/lib/python3.6/site-packages/rest_framework/viewsets.py", line 125, in view
Sep 30 17:11:21 xxx pulpcore-api[244250]:     return self.dispatch(request, *args, **kwargs)
Sep 30 17:11:21 xxx pulpcore-api[244250]:   File "/usr/lib/python3.6/site-packages/rest_framework/views.py", line 509, in dispatch
Sep 30 17:11:21 xxx pulpcore-api[244250]:     response = self.handle_exception(exc)
Sep 30 17:11:21 xxx pulpcore-api[244250]:   File "/usr/lib/python3.6/site-packages/rest_framework/views.py", line 469, in handle_exception
Sep 30 17:11:21 xxx pulpcore-api[244250]:     self.raise_uncaught_exception(exc)
Sep 30 17:11:21 xxx pulpcore-api[244250]:   File "/usr/lib/python3.6/site-packages/rest_framework/views.py", line 480, in raise_uncaught_exception
Sep 30 17:11:21 xxx pulpcore-api[244250]:     raise exc
Sep 30 17:11:21 xxx pulpcore-api[244250]:   File "/usr/lib/python3.6/site-packages/rest_framework/views.py", line 506, in dispatch
Sep 30 17:11:21 xxx pulpcore-api[244250]:     response = handler(request, *args, **kwargs)
Sep 30 17:11:21 xxx pulpcore-api[244250]:   File "/usr/lib/python3.6/site-packages/rest_framework/mixins.py", line 43, in list
Sep 30 17:11:21 xxx pulpcore-api[244250]:     return self.get_paginated_response(serializer.data)
Sep 30 17:11:21 xxx pulpcore-api[244250]:   File "/usr/lib/python3.6/site-packages/rest_framework/serializers.py", line 745, in data
Sep 30 17:11:21 xxx pulpcore-api[244250]:     ret = super().data
Sep 30 17:11:21 xxx pulpcore-api[244250]:   File "/usr/lib/python3.6/site-packages/rest_framework/serializers.py", line 246, in data
Sep 30 17:11:21 xxx pulpcore-api[244250]:     self._data = self.to_representation(self.instance)
Sep 30 17:11:21 xxx pulpcore-api[244250]:   File "/usr/lib/python3.6/site-packages/rest_framework/serializers.py", line 664, in to_representation
Sep 30 17:11:21 xxx pulpcore-api[244250]:     self.child.to_representation(item) for item in iterable
Sep 30 17:11:21 xxx pulpcore-api[244250]:   File "/usr/lib/python3.6/site-packages/rest_framework/serializers.py", line 664, in <listcomp>
Sep 30 17:11:21 xxx pulpcore-api[244250]:     self.child.to_representation(item) for item in iterable
Sep 30 17:11:21 xxx pulpcore-api[244250]:   File "/usr/lib/python3.6/site-packages/rest_framework/serializers.py", line 515, in to_representation
Sep 30 17:11:21 xxx pulpcore-api[244250]:     ret[field.field_name] = field.to_representation(attribute)
Sep 30 17:11:21 xxx pulpcore-api[244250]:   File "/usr/lib/python3.6/site-packages/pulpcore/app/serializers/repository.py", line 360, in to_representation
Sep 30 17:11:21 xxx pulpcore-api[244250]:     item_dict = {"count": count_detail.count, "href": count_detail.content_href}
Sep 30 17:11:21 xxx pulpcore-api[244250]:   File "/usr/lib/python3.6/site-packages/pulpcore/app/models/repository.py", line 1027, in content_href
Sep 30 17:11:21 xxx pulpcore-api[244250]:     ctype_model = Content.objects.filter(pulp_type=self.content_type).first().cast().__class__
Sep 30 17:11:21 xxx pulpcore-api[244250]: AttributeError: 'NoneType' object has no attribute 'cast'
Sep 30 17:11:21 xxx pulpcore-api[244250]: pulp [e9c240744ab9495589cb7b252f7f91df]:  - - [30/Sep/2021:15:11:21 +0000] "GET /pulp/api/v3/repositories/rpm/rpm/8e8e0a36-93a5-4d38-b9be-cdfeee4cc951/versions/?limit=2000&offset=0 HTTP/1.1" 500 27 "-" "OpenAPI-Generator/3.13.3/ruby"

There’s been a similar report here: PulpDebClient::ApiError - HTTP 500 when running katello:delete_orphaned_content - #5 by rgp

FYI

ping @quba42 does this look familiar?

@Justin_Sherrill The two reports do look similar. I have not experienced anything like this before, but that could just be because I have never tested an orphan cleanup.

In general, I do not have a lot of experience with Pulp back-traces that do not pass through any pulp_deb plugin files. Which is not to say that it is not possible for deb content to cause some problem with orphan cleanup. I just don’t have a lot of experience with how to go about debugging that, so I am currently at a bit of a loss on what to do about it.

Oh you know, this traceback looks rpm related, while the other looks deb. So this doesn’t look deb-specific.

I’ll file a pulp issue for pulpcore and we’ll see what the pulp team says.

opened Issue #9481: AttributeError: 'NoneType' object has no attribute 'cast' thrown when listing repostiory versions - Pulp

1 Like