PulpRpmClient::ApiError HTTP 500 during sync repository

Support
1

Problem:
An http 500 error occurs when synchronizing some repositories.
The problem is occurring with the synchronization of the exact repository:
https://buildlogs.centos.org/centos/6/storage/x86_64/gluster-7/

Steps to reproduce:

  1. add the following repository upstream URL: Index of /centos/6/storage/x86_64/gluster-7
    and try to synchronize it.

Foreman & Katello versions:
Foreman 3.1.0 & Katello 4.3.0

Distribution and version:
CentOS Linux release 7.9.2009 (Core)

Other relevant data:
production.log:

 eccf95a8 | [ sidekiq ]
 eccf95a8 | [ concurrent-ruby ]
2022-02-22T12:36:35 [E|bac|eccf95a8] Error message: the server returns an error
 eccf95a8 | HTTP status code: 500
 eccf95a8 | Response headers: {"date"=>"Tue, 22 Feb 2022 11:36:35 GMT", "server"=>"gunicorn", "content-type"=>"text/html; charset=UTF-8", "x-frame-options"=>"DENY", "content-length"=>"145", "vary"=>"Cookie", "x-content-type-options"=>"nosniff", "referrer-policy"=>"same-origin", "correlation-id"=>"eccf95a8-cd4b-4e59-a081-0842214328f6", "access-control-expose-headers"=>"Correlation-ID", "via"=>"1.1 foreman.internal", "connection"=>"close"}
 eccf95a8 | Response body: 
 eccf95a8 | <!doctype html>
 eccf95a8 | <html lang="en">
 eccf95a8 | <head>
 eccf95a8 |   <title>Server Error (500)</title>
 eccf95a8 | </head>
 eccf95a8 | <body>
 eccf95a8 |   <h1>Server Error (500)</h1><p></p>
 eccf95a8 | </body>
 eccf95a8 | </html>
 eccf95a8 |  (PulpRpmClient::ApiError)
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/pulp_rpm_client-3.16.1/lib/pulp_rpm_client/api_client.rb:83:in `call_api'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/pulp_rpm_client-3.16.1/lib/pulp_rpm_client/api/repositories_rpm_api.rb:508:in `sync_with_http_info'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/pulp_rpm_client-3.16.1/lib/pulp_rpm_client/api/repositories_rpm_api.rb:452:in `sync'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.3.0.rc4/app/services/katello/pulp3/repository.rb:251:in `sync'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.3.0.rc4/app/lib/actions/pulp3/repository/sync.rb:13:in `invoke_external_task'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/action/polling.rb:84:in `initiate_external_action'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/action/polling.rb:19:in `run'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/action/cancellable.rb:14:in `run'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.3.0.rc4/app/lib/actions/pulp3/abstract_async_task.rb:10:in `run'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/action.rb:582:in `block (3 levels) in execute_run'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware/stack.rb:27:in `pass'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware.rb:19:in `pass'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware.rb:32:in `run'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware/stack.rb:23:in `call'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware/stack.rb:27:in `pass'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware.rb:19:in `pass'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.3.0.rc4/app/lib/actions/middleware/remote_action.rb:16:in `block in run'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.3.0.rc4/app/lib/actions/middleware/remote_action.rb:40:in `block in as_remote_user'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.3.0.rc4/app/models/katello/concerns/user_extensions.rb:21:in `cp_config'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.3.0.rc4/app/lib/actions/middleware/remote_action.rb:27:in `as_cp_user'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.3.0.rc4/app/lib/actions/middleware/remote_action.rb:39:in `as_remote_user'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/katello-4.3.0.rc4/app/lib/actions/middleware/remote_action.rb:16:in `run'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware/stack.rb:23:in `call'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware/stack.rb:27:in `pass'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware.rb:19:in `pass'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-5.2.0/app/lib/actions/middleware/rails_executor_wrap.rb:14:in `block in run'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/activesupport-6.0.3.7/lib/active_support/execution_wrapper.rb:88:in `wrap'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-5.2.0/app/lib/actions/middleware/rails_executor_wrap.rb:13:in `run'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware/stack.rb:23:in `call'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware/stack.rb:27:in `pass'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware.rb:19:in `pass'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/action/progress.rb:31:in `with_progress_calculation'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/action/progress.rb:17:in `run'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware/stack.rb:23:in `call'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware/stack.rb:27:in `pass'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware.rb:19:in `pass'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-5.2.0/app/lib/actions/middleware/load_setting_values.rb:20:in `run'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware/stack.rb:23:in `call'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware/stack.rb:27:in `pass'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware.rb:19:in `pass'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-5.2.0/app/lib/actions/middleware/keep_current_request_id.rb:15:in `block in run'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-5.2.0/app/lib/actions/middleware/keep_current_request_id.rb:52:in `restore_current_request_id'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-5.2.0/app/lib/actions/middleware/keep_current_request_id.rb:15:in `run'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware/stack.rb:23:in `call'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware/stack.rb:27:in `pass'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware.rb:19:in `pass'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-5.2.0/app/lib/actions/middleware/keep_current_timezone.rb:15:in `block in run'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-5.2.0/app/lib/actions/middleware/keep_current_timezone.rb:44:in `restore_curent_timezone'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-5.2.0/app/lib/actions/middleware/keep_current_timezone.rb:15:in `run'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware/stack.rb:23:in `call'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware/stack.rb:27:in `pass'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware.rb:19:in `pass'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-5.2.0/app/lib/actions/middleware/keep_current_taxonomies.rb:15:in `block in run'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-5.2.0/app/lib/actions/middleware/keep_current_taxonomies.rb:45:in `restore_current_taxonomies'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-5.2.0/app/lib/actions/middleware/keep_current_taxonomies.rb:15:in `run'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware/stack.rb:23:in `call'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware/stack.rb:27:in `pass'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware.rb:19:in `pass'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware.rb:32:in `run'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware/stack.rb:23:in `call'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware/stack.rb:27:in `pass'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware.rb:19:in `pass'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-5.2.0/app/lib/actions/middleware/keep_current_user.rb:15:in `block in run'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-5.2.0/app/lib/actions/middleware/keep_current_user.rb:54:in `restore_curent_user'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/foreman-tasks-5.2.0/app/lib/actions/middleware/keep_current_user.rb:15:in `run'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware/stack.rb:23:in `call'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/middleware/world.rb:31:in `execute'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/action.rb:581:in `block (2 levels) in execute_run'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/action.rb:580:in `catch'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/action.rb:580:in `block in execute_run'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/action.rb:483:in `block in with_error_handling'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/action.rb:483:in `catch'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/action.rb:483:in `with_error_handling'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/action.rb:575:in `execute_run'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/action.rb:296:in `execute'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:18:in `block (2 levels) in execute'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/execution_plan/steps/abstract.rb:167:in `with_meta_calculation'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:17:in `block in execute'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:32:in `open_action'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/execution_plan/steps/abstract_flow_step.rb:16:in `execute'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/director.rb:69:in `execute'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/executors/sidekiq/worker_jobs.rb:11:in `block (2 levels) in perform'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/executors.rb:18:in `run_user_code'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/executors/sidekiq/worker_jobs.rb:9:in `block in perform'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/executors/sidekiq/worker_jobs.rb:25:in `with_telemetry'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/executors/sidekiq/worker_jobs.rb:8:in `perform'
 eccf95a8 | /opt/theforeman/tfm/root/usr/share/gems/gems/dynflow-1.6.2/lib/dynflow/executors/sidekiq/serialization.rb:27:in `perform'
 eccf95a8 | [ sidekiq ]
 eccf95a8 | [ concurrent-ruby ]

/var/log/messages:

Feb 24 11:28:55 foreman pulpcore-api: pulp [e2601bd6-70a5-4a87-ace3-a386280e3e30]:  - - [24/Feb/2022:10:28:55 +0000] "GET /pulp/api/v3/status HTTP/1.1" 301 0 "-" "rest-client/2.0.2 (linux x86_64) ruby/2.7.4p191"
Feb 24 11:28:55 foreman pulpcore-api: pulp [e2601bd6-70a5-4a87-ace3-a386280e3e30]:  - - [24/Feb/2022:10:28:55 +0000] "GET /pulp/api/v3/status/ HTTP/1.1" 200 3074 "-" "rest-client/2.0.2 (linux x86_64) ruby/2.7.4p191"
Feb 24 11:28:57 foreman pulpcore-api: pulp [e2601bd6-70a5-4a87-ace3-a386280e3e30]: django.request:ERROR: Internal Server Error: /pulp/api/v3/remotes/rpm/rpm/89e5b587-2295-4f1d-a49d-c0e8ed518c67/
Feb 24 11:28:57 foreman pulpcore-api: Traceback (most recent call last):
Feb 24 11:28:57 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib64/python3.8/site-packages/cryptography/fernet.py", line 96, in _get_unverified_token_data
Feb 24 11:28:57 foreman pulpcore-api: data = base64.urlsafe_b64decode(token)
Feb 24 11:28:57 foreman pulpcore-api: File "/opt/rh/rh-python38/root/usr/lib64/python3.8/base64.py", line 133, in urlsafe_b64decode
Feb 24 11:28:57 foreman pulpcore-api: return b64decode(s)
Feb 24 11:28:57 foreman pulpcore-api: File "/opt/rh/rh-python38/root/usr/lib64/python3.8/base64.py", line 87, in b64decode
Feb 24 11:28:57 foreman pulpcore-api: return binascii.a2b_base64(s)
Feb 24 11:28:57 foreman pulpcore-api: binascii.Error: Incorrect padding
Feb 24 11:28:57 foreman pulpcore-api: During handling of the above exception, another exception occurred:
Feb 24 11:28:57 foreman pulpcore-api: Traceback (most recent call last):
Feb 24 11:28:57 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/core/handlers/exception.py", line 47, in inner
Feb 24 11:28:57 foreman pulpcore-api: response = get_response(request)
Feb 24 11:28:57 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/core/handlers/base.py", line 181, in _get_response
Feb 24 11:28:57 foreman pulpcore-api: response = wrapped_callback(request, *callback_args, **callback_kwargs)
Feb 24 11:28:57 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/views/decorators/csrf.py", line 54, in wrapped_view
Feb 24 11:28:57 foreman pulpcore-api: return view_func(*args, **kwargs)
Feb 24 11:28:57 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/viewsets.py", line 125, in view
Feb 24 11:28:57 foreman pulpcore-api: return self.dispatch(request, *args, **kwargs)
Feb 24 11:28:57 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/views.py", line 509, in dispatch
Feb 24 11:28:57 foreman pulpcore-api: response = self.handle_exception(exc)
Feb 24 11:28:57 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/views.py", line 469, in handle_exception
Feb 24 11:28:57 foreman pulpcore-api: self.raise_uncaught_exception(exc)
Feb 24 11:28:57 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/views.py", line 480, in raise_uncaught_exception
Feb 24 11:28:57 foreman pulpcore-api: raise exc
Feb 24 11:28:57 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/views.py", line 506, in dispatch
Feb 24 11:28:57 foreman pulpcore-api: response = handler(request, *args, **kwargs)
Feb 24 11:28:57 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/pulpcore/app/viewsets/base.py", line 470, in partial_update
Feb 24 11:28:57 foreman pulpcore-api: return self.update(request, *args, **kwargs)
Feb 24 11:28:57 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/pulpcore/app/viewsets/base.py", line 452, in update
Feb 24 11:28:57 foreman pulpcore-api: instance = self.get_object()
Feb 24 11:28:57 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/generics.py", line 96, in get_object
Feb 24 11:28:57 foreman pulpcore-api: obj = get_object_or_404(queryset, **filter_kwargs)
Feb 24 11:28:57 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/generics.py", line 19, in get_object_or_404
Feb 24 11:28:57 foreman pulpcore-api: return _get_object_or_404(queryset, *filter_args, **filter_kwargs)
Feb 24 11:28:57 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/shortcuts.py", line 76, in get_object_or_404
Feb 24 11:28:57 foreman pulpcore-api: return queryset.get(*args, **kwargs)
Feb 24 11:28:57 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/db/models/query.py", line 431, in get
Feb 24 11:28:57 foreman pulpcore-api: num = len(clone)
Feb 24 11:28:57 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/db/models/query.py", line 262, in __len__
Feb 24 11:28:57 foreman pulpcore-api: self._fetch_all()
Feb 24 11:28:57 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/db/models/query.py", line 1324, in _fetch_all
Feb 24 11:28:57 foreman pulpcore-api: self._result_cache = list(self._iterable_class(self))
Feb 24 11:28:57 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/db/models/query.py", line 68, in __iter__
Feb 24 11:28:57 foreman pulpcore-api: for row in compiler.results_iter(results):
Feb 24 11:28:57 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/db/models/sql/compiler.py", line 1122, in apply_converters
Feb 24 11:28:57 foreman pulpcore-api: value = converter(value, expression, connection)
Feb 24 11:28:57 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/pulpcore/app/models/fields.py", line 104, in from_db_value
Feb 24 11:28:57 foreman pulpcore-api: return force_str(self._fernet.decrypt(force_bytes(value)))
Feb 24 11:28:57 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib64/python3.8/site-packages/cryptography/fernet.py", line 75, in decrypt
Feb 24 11:28:57 foreman pulpcore-api: timestamp, data = Fernet._get_unverified_token_data(token)
Feb 24 11:28:57 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib64/python3.8/site-packages/cryptography/fernet.py", line 98, in _get_unverified_token_data
Feb 24 11:28:57 foreman pulpcore-api: raise InvalidToken
Feb 24 11:28:57 foreman pulpcore-api: cryptography.fernet.InvalidToken
Feb 24 11:28:57 foreman pulpcore-api: pulp [e2601bd6-70a5-4a87-ace3-a386280e3e30]:  - - [24/Feb/2022:10:28:57 +0000] "PATCH /pulp/api/v3/remotes/rpm/rpm/89e5b587-2295-4f1d-a49d-c0e8ed518c67/ HTTP/1.1" 500 145 "-" "OpenAPI-Generator/3.16.1/ruby"
Feb 24 11:28:58 foreman qdrouterd: SERVER (info) [C464018] Connection from 10.2.1.176:50898 (to :5647) failed: amqp:resource-limit-exceeded local-idle-timeout expired
Feb 24 11:28:58 foreman qdrouterd: ROUTER_CORE (info) [C464018][L1196864] Link detached: del=0 presett=0 psdrop=0 acc=0 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no
Feb 24 11:28:58 foreman qdrouterd: ROUTER_CORE (info) [C464018] Connection Closed
Feb 24 11:28:58 foreman qdrouterd: ROUTER_CORE (info) [C4][L1196865] Link detached: del=0 presett=0 psdrop=0 acc=0 rej=0 rel=0 mod=0 delay1=0 delay10=0 blocked=no
Feb 24 11:28:58 foreman pulpcore-api: pulp [e2601bd6-70a5-4a87-ace3-a386280e3e30]: django.request:ERROR: Internal Server Error: /pulp/api/v3/repositories/rpm/rpm/b4a448e8-896c-4fec-8ee2-fcdf4307f2fd/sync/
Feb 24 11:28:58 foreman pulpcore-api: Traceback (most recent call last):
Feb 24 11:28:58 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib64/python3.8/site-packages/cryptography/fernet.py", line 96, in _get_unverified_token_data
Feb 24 11:28:58 foreman pulpcore-api: data = base64.urlsafe_b64decode(token)
Feb 24 11:28:58 foreman pulpcore-api: File "/opt/rh/rh-python38/root/usr/lib64/python3.8/base64.py", line 133, in urlsafe_b64decode
Feb 24 11:28:58 foreman pulpcore-api: return b64decode(s)
Feb 24 11:28:58 foreman pulpcore-api: File "/opt/rh/rh-python38/root/usr/lib64/python3.8/base64.py", line 87, in b64decode
Feb 24 11:28:58 foreman pulpcore-api: return binascii.a2b_base64(s)
Feb 24 11:28:58 foreman pulpcore-api: binascii.Error: Incorrect padding
Feb 24 11:28:58 foreman pulpcore-api: During handling of the above exception, another exception occurred:
Feb 24 11:28:58 foreman pulpcore-api: Traceback (most recent call last):
Feb 24 11:28:58 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/core/handlers/exception.py", line 47, in inner
Feb 24 11:28:58 foreman pulpcore-api: response = get_response(request)
Feb 24 11:28:58 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/core/handlers/base.py", line 181, in _get_response
Feb 24 11:28:58 foreman pulpcore-api: response = wrapped_callback(request, *callback_args, **callback_kwargs)
Feb 24 11:28:58 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/views/decorators/csrf.py", line 54, in wrapped_view
Feb 24 11:28:58 foreman pulpcore-api: return view_func(*args, **kwargs)
Feb 24 11:28:58 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/viewsets.py", line 125, in view
Feb 24 11:28:58 foreman pulpcore-api: return self.dispatch(request, *args, **kwargs)
Feb 24 11:28:58 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/views.py", line 509, in dispatch
Feb 24 11:28:58 foreman pulpcore-api: response = self.handle_exception(exc)
Feb 24 11:28:58 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/views.py", line 469, in handle_exception
Feb 24 11:28:58 foreman pulpcore-api: self.raise_uncaught_exception(exc)
Feb 24 11:28:58 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/views.py", line 480, in raise_uncaught_exception
Feb 24 11:28:58 foreman pulpcore-api: raise exc
Feb 24 11:28:58 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/views.py", line 506, in dispatch
Feb 24 11:28:58 foreman pulpcore-api: response = handler(request, *args, **kwargs)
Feb 24 11:28:58 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/pulp_rpm/app/viewsets.py", line 130, in sync
Feb 24 11:28:58 foreman pulpcore-api: serializer.is_valid(raise_exception=True)
Feb 24 11:28:58 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/serializers.py", line 220, in is_valid
Feb 24 11:28:58 foreman pulpcore-api: self._validated_data = self.run_validation(self.initial_data)
Feb 24 11:28:58 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/serializers.py", line 419, in run_validation
Feb 24 11:28:58 foreman pulpcore-api: value = self.to_internal_value(data)
Feb 24 11:28:58 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/serializers.py", line 476, in to_internal_value
Feb 24 11:28:58 foreman pulpcore-api: validated_value = field.run_validation(primitive_value)
Feb 24 11:28:58 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/relations.py", line 153, in run_validation
Feb 24 11:28:58 foreman pulpcore-api: return super().run_validation(data)
Feb 24 11:28:58 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/fields.py", line 568, in run_validation
Feb 24 11:28:58 foreman pulpcore-api: value = self.to_internal_value(data)
Feb 24 11:28:58 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/relations.py", line 373, in to_internal_value
Feb 24 11:28:58 foreman pulpcore-api: return self.get_object(match.view_name, match.args, match.kwargs)
Feb 24 11:28:58 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/pulpcore/app/serializers/base.py", line 322, in get_object
Feb 24 11:28:58 foreman pulpcore-api: return super().get_object(*args, **kwargs).cast()
Feb 24 11:28:58 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/relations.py", line 318, in get_object
Feb 24 11:28:58 foreman pulpcore-api: return queryset.get(**lookup_kwargs)
Feb 24 11:28:58 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/db/models/query.py", line 431, in get
Feb 24 11:28:58 foreman pulpcore-api: num = len(clone)
Feb 24 11:28:58 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/db/models/query.py", line 262, in __len__
Feb 24 11:28:58 foreman pulpcore-api: self._fetch_all()
Feb 24 11:28:58 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/db/models/query.py", line 1324, in _fetch_all
Feb 24 11:28:58 foreman pulpcore-api: self._result_cache = list(self._iterable_class(self))
Feb 24 11:28:58 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/db/models/query.py", line 68, in __iter__
Feb 24 11:28:58 foreman pulpcore-api: for row in compiler.results_iter(results):
Feb 24 11:28:58 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/db/models/sql/compiler.py", line 1122, in apply_converters
Feb 24 11:28:58 foreman pulpcore-api: value = converter(value, expression, connection)
Feb 24 11:28:58 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/pulpcore/app/models/fields.py", line 104, in from_db_value
Feb 24 11:28:58 foreman pulpcore-api: return force_str(self._fernet.decrypt(force_bytes(value)))
Feb 24 11:28:58 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib64/python3.8/site-packages/cryptography/fernet.py", line 75, in decrypt
Feb 24 11:28:58 foreman pulpcore-api: timestamp, data = Fernet._get_unverified_token_data(token)
Feb 24 11:28:58 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib64/python3.8/site-packages/cryptography/fernet.py", line 98, in _get_unverified_token_data
Feb 24 11:28:58 foreman pulpcore-api: raise InvalidToken
Feb 24 11:28:58 foreman pulpcore-api: cryptography.fernet.InvalidToken
Feb 24 11:28:58 foreman pulpcore-api: pulp [e2601bd6-70a5-4a87-ace3-a386280e3e30]:  - - [24/Feb/2022:10:28:58 +0000] "POST /pulp/api/v3/repositories/rpm/rpm/b4a448e8-896c-4fec-8ee2-fcdf4307f2fd/sync/ HTTP/1.1" 500 145 "-" "OpenAPI-Generator/3.16.1/ruby"
1 Like
2

Hi!

Looking at the /var/log/messages error, it looks like pulp threw that error. I searched a bit and didn’t see anything similar, i’d recommend filing a pulp-rpm issue here:

and make sure to include all the logs from /var/log/messages that you have here.

Thanks

1 Like
3

@rvva Is this a repeatable error? Does it happen every time you do this particular sync?

I cannot reproduce, although I’m using the latest version of pulp_rpm, and not what is shipped in 4.3

Could you also provide the configuration of this repository, e.g. whether you have any certificates or proxies configured

4

Upvote, because I have this problem now too.
This problem appeared after updating to Foreman 3.1.2 with Katello 4.3.0.

6

@dralley Thanks for the reply. The error is not temporary. It occurs with every synchronization attempt.

Aditional information about repository:

Checksum Type:           sha256
Mirror on Sync:          no
Url:                     https://buildlogs.centos.org/centos/6/storage/x86_64/gluster-7/
Publish Via HTTP:        no
Published At:            https://foreman.internal/pulp/content/MyOrganization/Library/custom/CentOS_6/MyOrganization_glusterfs7_os_x86_64/
Relative Path:           MyOrganization/Library/custom/CentOS_6/MyOrganization_glusterfs7_os_x86_64
Download Policy:         immediate
HTTP Proxy Policy: global_default_http_proxy (None)

I also using custom SSL Client Cert and Key.
I use the same configuration in other repositories and the problem does not occur. I maintain over 100 repositories and the problem occurs when syncing only two of them.

I am not convinced that this is a problem actually with pulp_rpm.
The error occurs when trying to decode the cryptography token.
Would you help me with trying to capture this token? How can I do this on my foreman environment?

@foreman-materna
I can confirm that in the previous version of Foreman and Katello the problem did not occur.

7

What’s the other repo? (you said two, one of them is centos6-glusterfs7).

This is a public repo, so I’m not sure why the SSL Client cert/key are needed. What happens if you remove them? The purpose of providing those is that the serverr (e.g. the Red Hat CDN) needs to verify the identity and permissions of your client to download files, but in this case the server doesn’t care and doesn’t check any of that.

Also I just want to make sure you’re aware - centos6 is end-of-life, it’s not getting updates any longer. I know it’s probably not relevant to your issue but if you’ve still got centos6 systems connected to the internet, that’s a security risk.

@foreman-materna, could you also answer the same questions?

8

And I guess the obvious question that I missed, are those two repos the only ones using client certs? The only two using that particular client cert?

9

Good morning,

in may case I have problems with Red Hat repositories,
weirdly enough only with the RHEL 7 repositories, as far as I can see it.

10

The second repository is not public.
I store Centos 6 repositories for backward compatibility. For example, to restore an old system from a backup and have repositories working right away.

The only two using that particular client cert?

No, other repositories with this client certs sync succesfully.

What happens if you remove them?

The same error in /var/log/messages.

11

After upgrading from 4.2 to 4.3 I see the same error for the following repositories:

https://download.postgresql.org/pub/repos/yum/common/redhat/rhel-7-x86_64/
https://cdn.redhat.com/content/dist/rhel/server/7/7Server/x86_64/os
http://mirror.centos.org/centos/7/storage/x86_64/samba-411/
http://mirror.centos.org/centos/7/cloud/x86_64/openstack-queens/
http://mirror.centos.org/centos/7/cloud/x86_64/openstack-rocky/
http://mirror.centos.org/centos/7/cloud/x86_64/openstack-stein/
https://download.fedoraproject.org/pub/epel/8/Everything/x86_64/

All except the redhat repo are simple, public repositories.

12

O.K. Did some more testing, e.g. the postgresql repository https://download.postgresql.org/pub/repos/yum/common/redhat/rhel-7-x86_64/:

Sync always fails with traceback:

Mar 11 07:52:19 foreman pulpcore-api: pulp [1ad0f0ec-2c4b-49eb-9c5e-53c82afa8763]: django.request:ERROR: Internal Server Error: /pulp/api/v3/remotes/rpm/rpm/e49f9e02-43c5-41ac-8ed3-9a491e31c609/
Mar 11 07:52:19 foreman pulpcore-api: Traceback (most recent call last):
Mar 11 07:52:19 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/core/handlers/exception.py", line 47, in inner
Mar 11 07:52:19 foreman pulpcore-api: response = get_response(request)
Mar 11 07:52:19 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/core/handlers/base.py", line 181, in _get_response
Mar 11 07:52:19 foreman pulpcore-api: response = wrapped_callback(request, *callback_args, **callback_kwargs)
Mar 11 07:52:19 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/views/decorators/csrf.py", line 54, in wrapped_view
Mar 11 07:52:19 foreman pulpcore-api: return view_func(*args, **kwargs)
Mar 11 07:52:19 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/viewsets.py", line 125, in view
Mar 11 07:52:19 foreman pulpcore-api: return self.dispatch(request, *args, **kwargs)
Mar 11 07:52:19 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/views.py", line 509, in dispatch
Mar 11 07:52:19 foreman pulpcore-api: response = self.handle_exception(exc)
Mar 11 07:52:19 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/views.py", line 469, in handle_exception
Mar 11 07:52:19 foreman pulpcore-api: self.raise_uncaught_exception(exc)
Mar 11 07:52:19 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/views.py", line 480, in raise_uncaught_exception
Mar 11 07:52:19 foreman pulpcore-api: raise exc
Mar 11 07:52:19 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/views.py", line 506, in dispatch
Mar 11 07:52:19 foreman pulpcore-api: response = handler(request, *args, **kwargs)
Mar 11 07:52:19 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/pulpcore/app/viewsets/base.py", line 470, in partial_update
Mar 11 07:52:19 foreman pulpcore-api: return self.update(request, *args, **kwargs)
Mar 11 07:52:19 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/pulpcore/app/viewsets/base.py", line 452, in update
Mar 11 07:52:19 foreman pulpcore-api: instance = self.get_object()
Mar 11 07:52:19 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/generics.py", line 96, in get_object
Mar 11 07:52:19 foreman pulpcore-api: obj = get_object_or_404(queryset, **filter_kwargs)
Mar 11 07:52:19 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/generics.py", line 19, in get_object_or_404
Mar 11 07:52:19 foreman pulpcore-api: return _get_object_or_404(queryset, *filter_args, **filter_kwargs)
Mar 11 07:52:19 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/shortcuts.py", line 76, in get_object_or_404
Mar 11 07:52:19 foreman pulpcore-api: return queryset.get(*args, **kwargs)
Mar 11 07:52:19 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/db/models/query.py", line 431, in get
Mar 11 07:52:19 foreman pulpcore-api: num = len(clone)
Mar 11 07:52:19 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/db/models/query.py", line 262, in __len__
Mar 11 07:52:19 foreman pulpcore-api: self._fetch_all()
Mar 11 07:52:19 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/db/models/query.py", line 1324, in _fetch_all
Mar 11 07:52:19 foreman pulpcore-api: self._result_cache = list(self._iterable_class(self))
Mar 11 07:52:19 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/db/models/query.py", line 68, in __iter__
Mar 11 07:52:19 foreman pulpcore-api: for row in compiler.results_iter(results):
Mar 11 07:52:19 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/db/models/sql/compiler.py", line 1122, in apply_converters
Mar 11 07:52:19 foreman pulpcore-api: value = converter(value, expression, connection)
Mar 11 07:52:19 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/pulpcore/app/models/fields.py", line 104, in from_db_value
Mar 11 07:52:19 foreman pulpcore-api: return force_str(self._fernet.decrypt(force_bytes(value)))
Mar 11 07:52:19 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib64/python3.8/site-packages/cryptography/fernet.py", line 75, in decrypt
Mar 11 07:52:19 foreman pulpcore-api: timestamp, data = Fernet._get_unverified_token_data(token)
Mar 11 07:52:19 foreman pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib64/python3.8/site-packages/cryptography/fernet.py", line 101, in _get_unverified_token_data
Mar 11 07:52:19 foreman pulpcore-api: raise InvalidToken
Mar 11 07:52:19 foreman pulpcore-api: cryptography.fernet.InvalidToken

I cannot even do a simple GET on the remote:

# curl --cert /etc/pki/katello/certs/pulp-client.crt --key /etc/pki/katello/private/pulp-client.key https://foreman.example.com/pulp/api/v3/remotes/rpm/rpm/e49f9e02-43c5-41ac-8ed3-9a491e31c609/

<!doctype html>
<html lang="en">
<head>
  <title>Server Error (500)</title>
</head>
<body>
  <h1>Server Error (500)</h1><p></p>
</body>
</html>

It’s always throwing the same exception.

The exact same curl call works fine on my 4.2 installation before the upgrade and returns a nice json:

katello-4.2:# curl --cert /etc/pki/katello/certs/pulp-client.crt --key /etc/pki/katello/private/pulp-client.key https://foreman.example.com/pulp/api/v3/remotes/rpm/rpm/e49f9e02-43c5-41ac-8ed3-9a491e31c609/  | python -m json.tool
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100   602  100   602    0     0   3205      0 --:--:-- --:--:-- --:--:--  3236
{
    "ca_cert": null,
    "client_cert": null,
    "connect_timeout": null,
    "download_concurrency": 20,
    "headers": null,
    "max_retries": null,
    "name": "pgdg-common-el7-779671",
    "policy": "immediate",
    "proxy_url": null,
    "pulp_created": "2021-07-07T05:10:41.647207Z",
    "pulp_href": "/pulp/api/v3/remotes/rpm/rpm/e49f9e02-43c5-41ac-8ed3-9a491e31c609/",
    "pulp_labels": {},
    "pulp_last_updated": "2022-03-11T00:33:23.360558Z",
    "rate_limit": null,
    "sles_auth_token": null,
    "sock_connect_timeout": null,
    "sock_read_timeout": null,
    "tls_validation": true,
    "total_timeout": 300.0,
    "url": "https://download.postgresql.org/pub/repos/yum/common/redhat/rhel-7-x86_64/"
}
1 Like
13

I think I have found something in the database which may be the cause for this issue. From pulpcore 3.14 to 3.16 it seems some fields in the database are encrypted with a symmetric key in the file /etc/pulp/certs/database_fields.symmetric.key. The migration seems to be broken for some remotes:

pulpcore=# select pulp_id, name, url, username, length(username) from core_remote where username is not null and length(username) = 0;
               pulp_id                |           name            |                                    url                                     | username | length 
--------------------------------------+---------------------------+----------------------------------------------------------------------------+----------+--------
 e49f9e02-43c5-41ac-8ed3-9a491e31c609 | pgdg-common-el7-775402    | https://download.postgresql.org/pub/repos/yum/common/redhat/rhel-7-x86_64/ |          |      0
 1597297f-6333-4585-bb4e-7eeccf22be28 | samba-411-76723158        | http://mirror.centos.org/centos/7/storage/x86_64/samba-411/                |          |      0
 89758522-8af3-44fc-8ec0-26615664494c | openstack-rocky-7674227   | http://mirror.centos.org/centos/7/cloud/x86_64/openstack-rocky/            |          |      0
 27a18f61-21da-449a-965b-c68938e7ba34 | openstack-stein-76759204  | http://mirror.centos.org/centos/7/cloud/x86_64/openstack-stein/            |          |      0
 84e1651a-7fb0-4618-ae60-5bd7adb6b93f | openstack-queens-76733362 | http://mirror.centos.org/centos/7/cloud/x86_64/openstack-queens/           |          |      0
 57e722fc-ecf9-4daa-babb-249ca8d87668 | AppStream_x86_64-1715630  | http://mirror.centos.org/centos/8/AppStream/x86_64/os/                     |          |      0
 6f1837c9-d88f-42c2-861d-ff7e931885b9 | epel-1779394              | https://download.fedoraproject.org/pub/epel/8/Everything/x86_64/           |          |      0
(7 rows)

I haven’t checked all fields in the database which seem to be encrypted now.

What did notice, though, is that on the old 4.2 server with pulpcore 3.14 all those remotes have an empty username and password set, i.e. an empty string “” and not NULL like many others. However, the list of remotes on the old server with empty string username is longer than the affected ones on my 4.3 server.

So it seems to be an issue with the database migration from 3.14 to 3.16 and encryption of some fields in the database. The migration/encryption seems to fail is some cases and the original content remains in the database which makes decryption failed. This is also true for my affected rhel repository: I can see in the database that the remote contains the RSA private key in client_key, unlike the other rhel repos which contain some base64 encoded string in the client_key fields.

Thus the problem is that for some rows in the database (at least the core_remote table) encryption of the fields client_key, username, password, (proxy_username, proxy_password, too, I guess) fails during migration from 3.14 to 3.16 leaving the original content in the database. This leads to decryption failure in 3.16.

For whatever reason only a few repos are affected, mostly those which have empty strings for username, password instead of NULL like many others. However, even with empty strings for some remotes the encryption works while it doesn’t for others.

I hope it’s clear what I wrote and at least @dralley understands me…

1 Like
14

I think that makes some sense - I’ve filed Migration of encrypted fields between 3.14 and 3.16 is broken for some remotes · Issue #2327 · pulp/pulpcore · GitHub to track this upstream.

15

Thanks.

I was looking through the foreman-installer log from the upgrade but didn’t really find anything showing any problem. It’s not fully clear to me which step during foreman-install does the migration on the database and more important: it’s unclear to me if there is any low-level log of the migration process which may indicate some errors.

On a sidenote: I think pulpcore should consolidate the representation of “no username”, “no password”, etc. in the database. It’s pretty weird that some remotes in 3.14 use an empty string “” while others use NULL. In 3.16 the empty string gets encrypted which also doesn’t seem very useful…

I guess, in the future some database migration should consolidate this, probably setting NULL on the columns with the empty string…

16

@Justin_Sherrill

I guess this should also be filed as katello bug because anyone with more than 100 repositories/remotes in the database should probably defer upgrading from 4.2 to 4.3 until this has been fixed…

17

anyone with more than 100 repositories/remotes in the database should probably defer upgrading from 4.2 to 4.3 until this has been fixed…

I’m in general agreement with this

18

I don’t know if 100 was actually hit in my environment, but I am getting the same issue, 1 foreman server + 1 smart proxy, maybe 60 hosts. Repos are less than 30.

19

If it’s less then 100 remote repositories I can’t be really the exact same issue. You can easily check the total number in the database as root on your foreman server:

[root@foreman ~]# sudo -u postgres psql pulpcore -c 'select count(*) from core_remote;'
could not change directory to "/root": Permission denied
 count 
-------
   117
(1 row)

If that’s less than 100 (and you didn’t remove lots of repositories since the upgrade to 4.3 of course) I’d say it’s something else. If you have the same cryptography.fernet.InvalidToken although you had less than 100 rows in the table during migration from 4.2 to 4.3 it would require a closer look.

20

@gvde My count is 35. Indeed, I have removed a few repositories (got rid of CentOS 8) but I would reckon about 15 or so.

Here is what I see when syncing the smart proxy:

Mar  9 20:16:38 proxy pulpcore-api: pulp [fd038a28-78a8-4d5e-8ced-f5acfb108681]:  - - [09/Mar/2022:18:16:38 +0000] "GET /pulp/api/v3/remotes/rpm/rpm/?name=1-_CV_Subversion_CentOS_7-Production-1236c46e-6338-4e72-b7fa-598b57a91631 HTTP/1.1" 500 145 "-" "OpenAPI-Generator/3.16.1/ruby"
Mar  9 20:16:38 proxy pulpcore-api: pulp [fd038a28-78a8-4d5e-8ced-f5acfb108681]: django.request:ERROR: Internal Server Error: /pulp/api/v3/remotes/rpm/rpm/
Mar  9 20:16:38 proxy pulpcore-api: Traceback (most recent call last):
Mar  9 20:16:38 proxy pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/core/handlers/exception.py", line 47, in inner
Mar  9 20:16:38 proxy pulpcore-api: response = get_response(request)
Mar  9 20:16:38 proxy pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/core/handlers/base.py", line 181, in _get_response
Mar  9 20:16:38 proxy pulpcore-api: response = wrapped_callback(request, *callback_args, **callback_kwargs)
Mar  9 20:16:38 proxy pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/views/decorators/csrf.py", line 54, in wrapped_view
Mar  9 20:16:38 proxy pulpcore-api: return view_func(*args, **kwargs)
Mar  9 20:16:38 proxy pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/viewsets.py", line 125, in view
Mar  9 20:16:38 proxy pulpcore-api: return self.dispatch(request, *args, **kwargs)
Mar  9 20:16:38 proxy pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/views.py", line 509, in dispatch
Mar  9 20:16:38 proxy pulpcore-api: response = self.handle_exception(exc)
Mar  9 20:16:38 proxy pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/proxy/views.py", line 469, in handle_exception
Mar  9 20:16:38 proxy pulpcore-api: self.raise_uncaught_exception(exc)
Mar  9 20:16:38 proxy pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/views.py", line 480, in raise_uncaught_exception
Mar  9 20:16:38 proxy pulpcore-api: raise exc
Mar  9 20:16:38 proxy pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/views.py", line 506, in dispatch
Mar  9 20:16:38 proxy pulpcore-api: response = handler(request, *args, **kwargs)
Mar  9 20:16:38 proxy pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/mixins.py", line 40, in list
Mar  9 20:16:38 proxy pulpcore-api: page = self.paginate_queryset(queryset)
Mar  9 20:16:38 proxy pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/generics.py", line 171, in paginate_queryset
Mar  9 20:16:38 proxy pulpcore-api: return self.paginator.paginate_queryset(queryset, self.request, view=self)
Mar  9 20:16:38 proxy pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/rest_framework/pagination.py", line 395, in paginate_queryset
Mar  9 20:16:38 proxy pulpcore-api: return list(queryset[self.offset:self.offset + self.limit])
Mar  9 20:16:38 proxy pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/db/models/query.py", line 262, in __len__
Mar  9 20:16:38 proxy pulpcore-api: self._fetch_all()
Mar  9 20:16:38 proxy pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/db/models/query.py", line 1324, in _fetch_all
Mar  9 20:16:38 proxy pulpcore-api: self._result_cache = list(self._iterable_class(self))
Mar  9 20:16:38 proxy pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/db/models/query.py", line 68, in __iter__
Mar  9 20:16:38 proxy pulpcore-api: for row in compiler.results_iter(results):
Mar  9 20:16:38 proxy pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/django/db/models/sql/compiler.py", line 1122, in apply_converters
Mar  9 20:16:38 proxy pulpcore-api: value = converter(value, expression, connection)
Mar  9 20:16:38 proxy pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib/python3.8/site-packages/pulpcore/app/models/fields.py", line 104, in from_db_value
Mar  9 20:16:38 proxy pulpcore-api: return force_str(self._fernet.decrypt(force_bytes(value)))
Mar  9 20:16:38 proxy pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib64/python3.8/site-packages/cryptography/fernet.py", line 75, in decrypt
Mar  9 20:16:38 proxy pulpcore-api: timestamp, data = Fernet._get_unverified_token_data(token)
Mar  9 20:16:38 proxy pulpcore-api: File "/opt/theforeman/tfm-pulpcore/root/usr/lib64/python3.8/site-packages/cryptography/fernet.py", line 101, in _get_unverified_token_data
Mar  9 20:16:38 proxy pulpcore-api: raise InvalidToken
Mar  9 20:16:38 proxy pulpcore-api: cryptography.fernet.InvalidToken
Mar  9 20:16:38 proxy pulpcore-api: pulp [fd038a28-78a8-4d5e-8ced-f5acfb108681]:  - - [09/Mar/2022:18:16:38 +0000] "GET /pulp/api/v3/remotes/rpm/rpm/?name=1-CentOS_7-Production-1236c46e-6338-4e72-b7fa-598b57a91631 HTTP/1.1" 500 145 "-" "OpenAPI-Generator/3.16.1/ruby"
21

O.K. That’s on the proxy. Run the psql command on the proxy and it’ll show a much larger number. It’s the same problem. The proxy loads each publication from the main server, i.e. it has remotes for each content view in each lifecycle environment.

That means for the content proxy, the whole problem is much bigger…