Hide Forgot
Description of problem: Existing snapshot tasks are not executed until we issue a request to a web service. Version-Release number of selected component (if applicable): pulp-common-0.0.214-1.el6.noarch pulp-client-0.0.214-1.el6.noarch pulp-ec2-0.0.229-1.el6.noarch Example from logs Http was restarted around 10/3 21:36 A webservice request was executed around 10/4 15:52 2011-10-03 21:36:37,220 28878:139738177890272: pulp.server.async:INFO: async:333 Task reply handler, started. 2011-10-03 21:36:37,221 28878:139737810974464: gofer.messaging.broker:INFO: broker:100 connecting: {ec2-174-129-28-114.compute-1.amazonaws.com:5674}: transport=SSL host=ec2-174-129-28-114.compute-1.amazonaws.com port=5674 cacert=/etc/pki/rhua/qpid-ca.crt clientcert=/etc/pki/rhua/qpid-client.crt 2011-10-03 21:36:37,242 28878:139737810974464: gofer.messaging.broker:INFO: broker:103 {ec2-174-129-28-114.compute-1.amazonaws.com:5674} connected to AMQP 2011-10-04 15:52:10,198 28878:139737555789568: pulp.server.db.connection:INFO: connection:46 Attempting Database connection with seeds = localhost 2011-10-04 15:52:10,210 28878:139737555789568: pulp.server.db.connection:INFO: connection:51 Database connection established with: seeds = localhost, name = pulp_database 2011-10-04 15:52:10,346 28878:139737555789568: pulp.server.async:INFO: async:133 Loaded Task from database: Task 012df557-eddd-11e0-865d-12313d224a2d: _sync(rhui-5-mrg-g-2.0-debug-5.6-i386, synchronizer=<pulp.server.api.synchronizers.YumSynchronizer object at 0x7f17245e9190>, progress_callback=<bound method RepoSyncTask.progress_callback of <pulp.server.api.repo_sync_task.RepoSyncTask object at 0x7f17245e9090>>) 2011-10-04 15:52:10,348 28878:139737555789568: pulp.server.async:INFO: async:133 Loaded Task from database: Task 0129a382-eddd-11e0-8641-12313d224a2d: _sync(rhui-5-mrg-g-2.0-debug-5.7-i386, synchronizer=<pulp.server.api.synchronizers.YumSynchronizer object at 0x7f17245137d0>, progress_callback=<bound method RepoSyncTask.progress_callback of <pulp.server.api.repo_sync_task.RepoSyncTask object at 0x7f1724513850>>)
moved all of initialization into webservices.wsgi and pointed WSGIImportScript to that file as well in the apache config
set tracker bug. 746803
Please share the steps to verify/reproduce this.
Kick off several repo syncs, so that the tasks will be running for a few minutes at least. While the repo syncs are still running and have not yet all finished, do a "service pulp-server restart". After the restart, look in /var/log/pulp/pulp.log to verify the syncs got restarted and continued to run. Don't use rhui-manager or pulp-admin before looking in pulp.log and verifying that the syncs got restarted. Otherwise, you'll have triggered the old behavior that required an apache request to trigger the tasks.
Verified this defect as per comment5 with new RHUI ISO: RHEL-6.1-RHUI-2.0.1-20111017.0-Server-x86_64-DVD1.iso I kicked off the repo sync for rhl6 optional repo: ------------------------------------------------------------------------------ -= Red Hat Update Infrastructure Management Tool =- -= Repository Synchronization Status =- Last Refreshed: 12:46:24 (updated every 5 seconds, ctrl+c to exit) Next Sync Last Sync Last Result ------------------------------------------------------------------------------ Red Hat Enterprise Linux Server 6 Optional (RPMs) (6.1-i386) In Progress Never Never while sync was in in-progress state, I restarted the pulp-server service. After restarting the pulp-server service sync got restarted. I verified this with pulp.log and grinder logs. After restarting the pulp-server service, following logs generated: ===================================================================== 2011-10-21 12:46:43,532 17636:140164956788704: pulp.server.db.connection:INFO: connection:46 Attempting Database connection with seeds = dhcp201-133.englab.pnq.redhat.com 2011-10-21 12:46:43,539 17636:140164956788704: pulp.server.db.connection:INFO: connection:51 Database connection established with: seeds = dhcp201-133.englab.pnq.redhat.com, name = pulp_database 2011-10-21 12:46:43,756 17636:140164589573888: gofer.messaging.broker:INFO: broker:100 connecting: {dhcp201-133.englab.pnq.redhat.com:5674}: transport=SSL host=dhcp201-133.englab.pnq.redhat.com port=5674 cacert=/etc/pki/rhua/qpid-ca.crt clientcert=/etc/pki/rhua/qpid-client.crt 2011-10-21 12:46:43,805 17636:140164956788704: pulp.server.async:INFO: async:133 Loaded Task from database: Task 4b303e35-fbb4-11e0-9305-52540074d4bb: _sync(rhel-server-6-optional-6.1-i386, synchronizer=<pulp.server.api.synchronizers.YumSynchronizer object at 0x7f7a94025f50>, skip_dict={}, max_speed=None, threads=None, progress_callback=<bound method RepoSyncTask.progress_callback of <pulp.server.api.repo_sync_task.RepoSyncTask object at 0x7f7ab44f4bd0>>) 2011-10-21 12:46:43,821 17636:140164589573888: gofer.messaging.broker:INFO: broker:103 {dhcp201-133.englab.pnq.redhat.com:5674} connected to AMQP 2011-10-21 12:46:43,837 17636:140164558104320: pulp.server.api.repo_sync:INFO: repo_sync:212 Sync invoked for repo <rhel-server-6-optional-6.1-i386> 2011-10-21 12:46:43,838 17636:140164558104320: pulp.server.api.repo_sync:INFO: repo_sync:222 Sync of rhel-server-6-optional-6.1-i386 starting, skip_dict = {} 2011-10-21 12:46:43,840 17636:140164558104320: pulp.server.api.synchronizers:INFO: synchronizers:405 cacert = </etc/pki/content/rhel-server-6-optional-6.1-i386/feed-rhel-server-6-optional-6.1-i386.ca>, cert = </etc/pki/content/rhel-server-6-optional-6.1-i386/feed-rhel-server-6-optional-6.1-i386.cert> 2011-10-21 12:46:43,843 17636:140164558104320: pulp.server.api.synchronizers:INFO: synchronizers:453 Fetching repo to </var/lib/pulp//repos/content/dist/rhel/rhui/server/6/6.1/i386/optional/os> with verify_options <{'checksum': False, 'size': False}> 2011-10-21 12:46:43,900 17636:140164956788704: pulp:WARNING: scheduler:122 IntervalScheduler created with start time more than one interval in the past: 2011-10-21 05:26:34+05:30, 1:00:00 2011-10-21 12:46:43,906 17636:140164956788704: pulp.server.tasking.task:WARNING: task:299 Task a13dfd54-fbb4-11e0-86fb-52540074d4bb: _sync(rhui-2.0-6.1-i386, synchronizer=<pulp.server.api.synchronizers.YumSynchronizer object at 0x7f7a94034290>, progress_callback=<bound method RepoSyncTask.progress_callback of <pulp.server.api.repo_sync_task.RepoSyncTask object at 0x7f7a940340d0>>) missed 7 scheduled runs 2011-10-21 12:46:43,906 17636:140164956788704: pulp:INFO: scheduled_sync:240 Added scheduled sync for rhui-2.0-6.1-i386 to task queue 2011-10-21 12:46:43,907 17636:140164956788704: pulp:WARNING: scheduler:122 IntervalScheduler created with start time more than one interval in the past: 2011-10-21 05:26:43+05:30, 1:00:00 2011-10-21 12:46:43,917 17636:140164956788704: pulp.server.tasking.task:WARNING: task:299 Task a13f3142-fbb4-11e0-8703-52540074d4bb: _sync(rhui-2.0-6.0-x86_64, synchronizer=<pulp.server.api.synchronizers.YumSynchronizer object at 0x7f7a9402cf10>, progress_callback=<bound method RepoSyncTask.progress_callback of <pulp.server.api.repo_sync_task.RepoSyncTask object at 0x7f7a9402cc90>>) missed 7 scheduled runs 2011-10-21 12:46:43,918 17636:140164956788704: pulp:INFO: scheduled_sync:240 Added scheduled sync for rhui-2.0-6.0-x86_64 to task queue 2011-10-21 12:46:43,919 17636:140164956788704: pulp:WARNING: scheduler:122 IntervalScheduler created with start time more than one interval in the past: 2011-10-21 05:26:31+05:30, 1:00:00 2011-10-21 12:46:43,927 17636:140164956788704: pulp.server.tasking.task:WARNING: task:299 Task a1410382-fbb4-11e0-870f-52540074d4bb: _sync(rhui-2.0-6.0-i386, synchronizer=<pulp.server.api.synchronizers.YumSynchronizer object at 0x7f7a9402c950>, progress_callback=<bound method RepoSyncTask.progress_callback of <pulp.server.api.repo_sync_task.RepoSyncTask object at 0x7f7a9402ca90>>) missed 7 scheduled runs 2011-10-21 12:46:43,928 17636:140164956788704: pulp:INFO: scheduled_sync:240 Added scheduled sync for rhui-2.0-6.0-i386 to task queue 2011-10-21 12:46:43,930 17636:140164956788704: pulp:WARNING: scheduler:122 IntervalScheduler created with start time more than one interval in the past: 2011-10-21 05:26:40+05:30, 1:00:00 2011-10-21 12:46:43,939 17636:140164956788704: pulp.server.tasking.task:WARNING: task:299 Task a1428ca1-fbb4-11e0-8719-52540074d4bb: _sync(rhui-2.0-6Server-i386, synchronizer=<pulp.server.api.synchronizers.YumSynchronizer object at 0x7f7a9402cad0>, progress_callback=<bound method RepoSyncTask.progress_callback of <pulp.server.api.repo_sync_task.RepoSyncTask object at 0x7f7a9402cbd0>>) missed 7 scheduled runs 2011-10-21 12:46:43,940 17636:140164956788704: pulp:INFO: scheduled_sync:240 Added scheduled sync for rhui-2.0-6Server-i386 to task queue 2011-10-21 12:46:43,941 17636:140164956788704: pulp:WARNING: scheduler:122 IntervalScheduler created with start time more than one interval in the past: 2011-10-21 05:26:29+05:30, 1:00:00 2011-10-21 12:46:43,951 17636:140164956788704: pulp.server.tasking.task:WARNING: task:299 Task a1445fbd-fbb4-11e0-8725-52540074d4bb: _sync(rhui-2.0-6Server-x86_64, synchronizer=<pulp.server.api.synchronizers.YumSynchronizer object at 0x7f7a9402cb50>, progress_callback=<bound method RepoSyncTask.progress_callback of <pulp.server.api.repo_sync_task.RepoSyncTask object at 0x7f7a9402cb90>>) missed 7 scheduled runs 2011-10-21 12:46:43,952 17636:140164956788704: pulp:INFO: scheduled_sync:240 Added scheduled sync for rhui-2.0-6Server-x86_64 to task queue 2011-10-21 12:46:43,953 17636:140164956788704: pulp:WARNING: scheduler:122 IntervalScheduler created with start time more than one interval in the past: 2011-10-21 05:26:37+05:30, 1:00:00 2011-10-21 12:46:43,963 17636:140164956788704: pulp.server.tasking.task:WARNING: task:299 Task a1463a51-fbb4-11e0-8731-52540074d4bb: _sync(rhui-2.0-6.1-x86_64, synchronizer=<pulp.server.api.synchronizers.YumSynchronizer object at 0x7f7a9402ca50>, progress_callback=<bound method RepoSyncTask.progress_callback of <pulp.server.api.repo_sync_task.RepoSyncTask object at 0x7f7a94034450>>) missed 7 scheduled runs 2011-10-21 12:46:43,964 17636:140164956788704: pulp:INFO: scheduled_sync:240 Added scheduled sync for rhui-2.0-6.1-x86_64 to task queue 2011-10-21 12:46:43,965 17636:140164956788704: pulp:INFO: scheduled_sync:240 Added scheduled sync for rhel-server-6-optional-6.1-i386 to task queue 2011-10-21 12:46:43,975 17636:140164956788704: pulp:WARNING: scheduler:122 IntervalScheduler created with start time more than one interval in the past: 2011-10-21 05:35:12+05:30, 1:00:00 2011-10-21 12:46:43,975 17636:140164956788704: pulp.server.tasking.task:WARNING: task:299 Task a14980b5-fbb4-11e0-8746-52540074d4bb: CdsApi.cds_sync(dhcp201-108.englab.pnq.redhat.com, ) missed 7 scheduled runs 2011-10-21 12:46:43,978 17636:140164956788704: pulp:INFO: scheduled_sync:252 Added sync for dhcp201-108.englab.pnq.redhat.com to task queue when i again checked the sync status, it was in progress: ============================================================ -= Repository Synchronization Status =- Last Refreshed: 12:53:42 (updated every 5 seconds, ctrl+c to exit) Next Sync Last Sync Last Result ------------------------------------------------------------------------------ Red Hat Enterprise Linux Server 6 Optional (RPMs) (6.1-i386) In Progress Never Never Red Hat Update Infrastructure 2.0 (RPMs) (6.0-i386)
Technical note added. If any revisions are required, please edit the "Technical Notes" field accordingly. All revisions will be proofread by the Engineering Content Services team. New Contents: Do not document
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://access.redhat.com/errata/RHBA-2017:0367