Katello repo sync not working

Support
,
#1

Problem:
When setting up a sync plan in foreman it doesn’t sync the repositories. The creation of the sync plan works without errors and it appears in the foreman UI. Doing a manual run of the sync plan works also, it just seems that the schedule doesn’t trigger the syncing.

Expected outcome:
Repositories synced on scheduled date & time.

Foreman and Proxy versions:
foreman-1.19.0-1.el7.noarch
foreman-proxy-1.19.0-1.el7.noarch
pulp-server-2.16.4-1.el7.noarch

Foreman and Proxy plugin versions:

Other relevant data:
[e.g. logs from Foreman and/or the Proxy, modified templates, commands issued, etc]
I don’t see any errors in the logs.

I need some help to debug that issue.
Is the sync task triggered by crond? I’ve not been able to figure out what triggers the syncing.

Thanks for any help.
rgds, Arsene

#2

How are you setting up the sync plan? What parameters are you setting?

#3

My sync-plan looks like:
ID: 7
Name: Daily Sync
Start Date: 2018/10/09 10:00:00
Interval: daily
Enabled: yes
Description: Daily Synchronization Plan
Created at: 2018/10/09 09:53:06
Updated at: 2018/10/09 09:55:58
Products:

  1. ID: 3
    Name: Katello
  2. ID: 4
    Name: Zabbix
  3. ID: 2
    Name: Extra Packages for Enterprise Linux
  4. ID: 5
    Name: Bacula
  5. ID: 1
    Name: CentOS

I’m able to start the sync-plan manually but it doesn’t start automatically at specified schedule time and I don’t see any error.
Is there a place where I can see if the job is in a scheduler/cron ?

Thanks for any help.

#4

Do you see a field recurring logic on the sync plan detail page you just created? What is the status of the recurring logic associated to the sync plan?

#5

That’s what I see on the UI:
(upload://Af0HcoMPzB7pV65JVVWR6c97nIZ.png) gnome-shell-screenshot-XN88QZ

I don’t see any entries in Monitor --> Recurring Logics

#6

My bad…Didn’t notice the version you were on.

Could you go to one of the products in the sync plan > tasks tab> You should see a task named “Add Sync Plan Products” .
Go to the Dynflow console for that task and see if the child task Actions::Pulp::Repository::UpdateSchedule was invoked and if it succeeded?

#7

Yes it seems that it did succeed.

image
image.png678×559 45.5 KB

#8

I could finally find some error in the journal log:

Oct 18 20:28:17 xxxxx.xxxx.xxxx.xxx pulp[10871]: pulp.server.event.http:INFO: [049abcae] (10871-98176) “FINISHED”}, “distribution”: {“items_total”: 0, “state”: “FINISHED”, “error_details”:
Oct 18 20:28:17 xxxxx.xxxx.xxxx.xxx pulp[10871]: pulp.server.event.http:ERROR: [049abcae] (10871-98176) HTTP Notification Failed
Oct 18 20:28:17 xxxxx.xxxx.xxxx.xxx pulp[10871]: pulp.server.event.http:ERROR: [049abcae] (10871-98176) Traceback (most recent call last):
Oct 18 20:28:17 xxxxx.xxxx.xxxx.xxx pulp[10871]: pulp.server.event.http:ERROR: [049abcae] (10871-98176) File “/usr/lib/python2.7/site-packages/pulp/server/event/http.py”, line 57, in send
Oct 18 20:28:17 xxxxx.xxxx.xxxx.xxx pulp[10871]: pulp.server.event.http:ERROR: [049abcae] (10871-98176) headers={‘Content-Type’: ‘application/json’}, timeout=15)
Oct 18 20:28:17 xxxxx.xxxx.xxxx.xxx pulp[10871]: pulp.server.event.http:ERROR: [049abcae] (10871-98176) File “/usr/lib/python2.7/site-packages/requests/api.py”, line 108, in post
Oct 18 20:28:17 xxxxx.xxxx.xxxx.xxx pulp[10871]: pulp.server.event.http:ERROR: [049abcae] (10871-98176) return request(‘post’, url, data=data, json=json, **kwargs)
Oct 18 20:28:17 xxxxx.xxxx.xxxx.xxx pulp[10871]: pulp.server.event.http:ERROR: [049abcae] (10871-98176) File “/usr/lib/python2.7/site-packages/requests/api.py”, line 50, in request
Oct 18 20:28:17xxxxx.xxxx.xxxx.xxx pulp[10871]: pulp.server.event.http:ERROR: [049abcae] (10871-98176) response = session.request(method=method, url=url, **kwargs)
Oct 18 20:28:17xxxxx.xxxx.xxxx.xxx pulp[10871]: pulp.server.event.http:ERROR: [049abcae] (10871-98176) File “/usr/lib/python2.7/site-packages/requests/sessions.py”, line 464, in request
Oct 18 20:28:17 xxxxx.xxxx.xxxx.xxx pulp[10871]: pulp.server.event.http:ERROR: [049abcae] (10871-98176) resp = self.send(prep, **send_kwargs)
Oct 18 20:28:17 xxxxx.xxxx.xxxx.xxx pulp[10871]: pulp.server.event.http:ERROR: [049abcae] (10871-98176) File “/usr/lib/python2.7/site-packages/requests/sessions.py”, line 576, in send
Oct 18 20:28:17 xxxxx.xxxx.xxxx.xxx pulp[10871]: pulp.server.event.http:ERROR: [049abcae] (10871-98176) r = adapter.send(request, **kwargs)
Oct 18 20:28:17 xxxxx.xxxx.xxxx.xxx pulp[10871]: pulp.server.event.http:ERROR: [049abcae] (10871-98176) File “/usr/lib/python2.7/site-packages/requests/adapters.py”, line 424, in send
Oct 18 20:28:17 xxxxx.xxxx.xxxx.xxx pulp[10871]: pulp.server.event.http:ERROR: [049abcae] (10871-98176) raise ConnectionError(e, request=request)
Oct 18 20:28:17 xxxxx.xxxx.xxxx.xxx pulp[10871]: pulp.server.event.http:ERROR: [049abcae] (10871-98176) ConnectionError: HTTPSConnectionPool(host=‘spfy-tfmd01.prd.sapify.ch’, port=443): Max r
Oct 18 20:28:17 xxxxx.xxxx.xxxx.xxx pulp[10881]: pulp.server.async.tasks:INFO: [aafb26e1] resetting consecutive failure count for schedule 5bbc5e83a9431605a30e2eec
Oct 18 20:28:17 xxxxx.xxxx.xxxx.xxx pulp[5466]: celery.worker.strategy:INFO: Received task: pulp.server.async.tasks._queue_reserved_task[b80bd154-250a-4edb-be3f-615942051bcb]

It seems that pulp isn’t able to connect to the foreman server because of an SSL certificate problem, but I’m not able to figure out which certificate it is. I’m using an external certificate for the foreman web interface.
I’ve tried to run foreman-installer again but it didn’t help.

Any Idea where I should investigate further?

Pulp tasks triggered by schedulers do not run
#9

I found these 2 fixes for the problem you are seeing:

https://pulp.plan.io/issues/3780
https://projects.theforeman.org/issues/24083

Once you apply the pulp patch, you can run the rake task update_sync_notifications. That should resolve the issue.

#10

I did apply the patch of both links and run foreman-rake katello:update_sync_notifications which return an error:
** Invoke katello:update_sync_notifications (first_time)
** Invoke environment (first_time)
** Execute environment
** Execute katello:update_sync_notifications
rake aborted!
RestClient::InternalServerError: 500 Internal Server Error
/opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-2.0.1/lib/restclient/abstract_response.rb:223:in exception_with_response' /opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-2.0.1/lib/restclient/abstract_response.rb:103:inreturn!’
/opt/theforeman/tfm/root/usr/share/gems/gems/runcible-2.8.1/lib/runcible/base.rb:93:in block in get_response' /opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-2.0.1/lib/restclient/request.rb:807:inprocess_result’
/opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-2.0.1/lib/restclient/request.rb:725:in block in transmit' /opt/rh/rh-ruby24/root/usr/share/ruby/net/http.rb:877:instart’
/opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-2.0.1/lib/restclient/request.rb:715:in transmit' /opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-2.0.1/lib/restclient/request.rb:145:inexecute’
/opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-2.0.1/lib/restclient/request.rb:52:in execute' /opt/theforeman/tfm/root/usr/share/gems/gems/rest-client-2.0.1/lib/restclient/resource.rb:51:inget’
/opt/theforeman/tfm/root/usr/share/gems/gems/runcible-2.8.1/lib/runcible/base.rb:92:in get_response' /opt/theforeman/tfm/root/usr/share/gems/gems/runcible-2.8.1/lib/runcible/base.rb:72:incall’
/opt/theforeman/tfm/root/usr/share/gems/gems/runcible-2.8.1/lib/runcible/resources/event_notifier.rb:48:in list' /opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.8.0/app/models/katello/glue/pulp/repo.rb:36:inensure_sync_notification’
/opt/theforeman/tfm/root/usr/share/gems/gems/katello-3.8.0/lib/katello/tasks/update_sync_notifications.rake:5:in block (2 levels) in <top (required)>' /opt/rh/rh-ruby24/root/usr/share/gems/gems/rake-12.0.0/lib/rake/task.rb:250:inblock in execute’
/opt/rh/rh-ruby24/root/usr/share/gems/gems/rake-12.0.0/lib/rake/task.rb:250:in each' /opt/rh/rh-ruby24/root/usr/share/gems/gems/rake-12.0.0/lib/rake/task.rb:250:inexecute’
/opt/rh/rh-ruby24/root/usr/share/gems/gems/rake-12.0.0/lib/rake/task.rb:194:in block in invoke_with_call_chain' /opt/rh/rh-ruby24/root/usr/share/ruby/monitor.rb:214:inmon_synchronize’
/opt/rh/rh-ruby24/root/usr/share/gems/gems/rake-12.0.0/lib/rake/task.rb:187:in invoke_with_call_chain' /opt/rh/rh-ruby24/root/usr/share/gems/gems/rake-12.0.0/lib/rake/task.rb:180:ininvoke’
/opt/rh/rh-ruby24/root/usr/share/gems/gems/rake-12.0.0/lib/rake/application.rb:152:in invoke_task' /opt/rh/rh-ruby24/root/usr/share/gems/gems/rake-12.0.0/lib/rake/application.rb:108:inblock (2 levels) in top_level’
/opt/rh/rh-ruby24/root/usr/share/gems/gems/rake-12.0.0/lib/rake/application.rb:108:in each' /opt/rh/rh-ruby24/root/usr/share/gems/gems/rake-12.0.0/lib/rake/application.rb:108:inblock in top_level’
/opt/rh/rh-ruby24/root/usr/share/gems/gems/rake-12.0.0/lib/rake/application.rb:117:in run_with_threads' /opt/rh/rh-ruby24/root/usr/share/gems/gems/rake-12.0.0/lib/rake/application.rb:102:intop_level’
/opt/rh/rh-ruby24/root/usr/share/gems/gems/rake-12.0.0/lib/rake/application.rb:80:in block in run' /opt/rh/rh-ruby24/root/usr/share/gems/gems/rake-12.0.0/lib/rake/application.rb:178:instandard_exception_handling’
/opt/rh/rh-ruby24/root/usr/share/gems/gems/rake-12.0.0/lib/rake/application.rb:77:in run' /opt/rh/rh-ruby24/root/usr/share/gems/gems/rake-12.0.0/exe/rake:27:in<top (required)>’
/opt/rh/rh-ruby24/root/usr/bin/rake:23:in load' /opt/rh/rh-ruby24/root/usr/bin/rake:23:in’
Tasks: TOP => katello:update_sync_notifications

And journald returns :

Oct 19 11:15:56 pulp[1564]: pulp.server.webservices.application:CRITICAL: *************************************************************
Oct 19 11:15:56 pulp[1564]: pulp.server.webservices.application:ERROR: (1564-97984) The Pulp server encountered an unexpected failure during initialization
Oct 19 11:15:56 pulp[1564]: pulp.server.webservices.application:ERROR: (1564-97984) Traceback (most recent call last):
Oct 19 11:15:56 pulp[1564]: pulp.server.webservices.application:ERROR: (1564-97984) File “/usr/lib/python2.7/site-packages/pulp/server/webservices/application.py”, line 111, in wsgi_application
Oct 19 11:15:56 pulp[1564]: pulp.server.webservices.application:ERROR: (1564-97984) _initialize_web_services()
Oct 19 11:15:56 pulp[1564]: pulp.server.webservices.application:ERROR: (1564-97984) File “/usr/lib/python2.7/site-packages/pulp/server/webservices/application.py”, line 66, in _initialize_web_services
Oct 19 11:15:56 pulp[1564]: pulp.server.webservices.application:ERROR: (1564-97984) initialization.initialize()
Oct 19 11:15:56 pulp[1564]: pulp.server.webservices.application:ERROR: (1564-97984) File “/usr/lib/python2.7/site-packages/pulp/server/initialization.py”, line 31, in initialize
Oct 19 11:15:56 pulp[1564]: pulp.server.webservices.application:ERROR: (1564-97984) db_connection.initialize()
Oct 19 11:15:56 pulp[1564]: pulp.server.webservices.application:ERROR: (1564-97984) File “/usr/lib/python2.7/site-packages/pulp/server/db/connection.py”, line 61, in initialize
Oct 19 11:15:56 pulp[1564]: pulp.server.webservices.application:ERROR: (1564-97984) raise RuntimeError("The database is already initialized. It is an error to call this "
Oct 19 11:15:56 pulp[1564]: pulp.server.webservices.application:ERROR: (1564-97984) RuntimeError: The database is already initialized. It is an error to call this function a second time.
Oct 19 11:15:56 pulp[1564]: pulp.server.webservices.application:CRITICAL: *************************************************************

I’m not able to set a new date/time for my sync-plan…

#11

Sorry the error was due to a typo during applying patches.
It now works.

Thanks a lot.