Bug 705998 - Sync errors in pulp.log while checking sync status using rhui-manager
Summary: Sync errors in pulp.log while checking sync status using rhui-manager
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Red Hat Update Infrastructure for Cloud Providers
Classification: Red Hat
Component: Tools
Version: 2.0
Hardware: x86_64
OS: Linux
unspecified
medium
Target Milestone: ---
: ---
Assignee: Jason Connor
QA Contact: wes hayutin
URL:
Whiteboard:
Depends On:
Blocks: rhui-20
TreeView+ depends on / blocked
 
Reported: 2011-05-19 06:39 UTC by Sachin Ghai
Modified: 2014-03-31 01:39 UTC (History)
2 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2012-05-31 12:56:21 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)

Description Sachin Ghai 2011-05-19 06:39:13 UTC
Description of problem:
I'm facing this issue since couple of days. When I checked the repo sync status using rhui-manger using an option "dr", this filled up the pulp.log with following messages.


2011-05-19 11:48:26,849 [WARNING][Dummy-2] schedule() @ task.py:192 - Task cecf3105-81df-11e0-b6a0-525400da69d0: cull_history(, ) missed 1 scheduled runs
2011-05-19 11:48:26,892 [ERROR][Dummy-2] clear_all_sync_in_progress() @ repo.py:73 - r = SON([(u'_id', u'rhui-1.2-5Server-x86_64'), (u'id', u'rhui-1.2-5Server-x86_64'), (u'sync_in_progress', False)])


Version-Release number of selected component (if applicable):
Pulp 0.171
rhui-tools 2.0.22

How reproducible:
Its seems to be a random, but generally appears while checking the status sync schedule.

Steps to Reproduce:

1. Check the sync status using "dr"
2. Then check logs on rhua server (/var/log/pulp/pulp/log)

  
Actual results:
Above error messages on rhua server in pulp.log

Expected results:
There shouldn't be any error messages in pulp.log

Additional info:

I checked the sync schedule using 'dr', here is the ouput:

rhui (sync) => dr

------------------------------------------------------------------------------
             -= Red Hat Update Infrastructure Management Tool =-


-= Repository Synchronization Status =-

Last Refreshed: 11:48:42
(updated every 50 seconds, ctrl+c to exit)

Next Sync                    Last Sync                    Last Result         
------------------------------------------------------------------------------
Red Hat Enterprise Linux Server 6 Releases (RPMs) (6Server-x86_64)
05-19-2011 12:24             05-18-2011 17:24             scheduled  

Red Hat Enterprise Linux Server 6 Updates (RPMs) (6Server-x86_64)
05-19-2011 12:26             05-18-2011 17:07             scheduled  

Red Hat Update Infrastructure 1.1 (RPMs) (5Server-i386)
05-19-2011 12:32             05-18-2011 08:02             scheduled  

Red Hat Update Infrastructure 1.1 (RPMs) (5Server-x86_64)
05-19-2011 12:32             05-18-2011 09:02             scheduled  

Red Hat Update Infrastructure 1.2 (RPMs) (5Server-i386)
05-19-2011 12:6              05-18-2011 12:36             scheduled  

Red Hat Update Infrastructure 1.2 (RPMs) (5Server-x86_64)
05-19-2011 12:6              05-18-2011 12:36             scheduled  


                                         Connected: dhcp193-157.pnq.redhat.com
------------------------------------------------------------------------------
^Crhui (sync) => 


Then I check the pulp.log, and foumd following errors;
[root@dhcp193-157 ~]# tail -f /var/log/pulp/pulp.log
2011-05-19 11:48:26,849 [WARNING][Dummy-2] schedule() @ task.py:192 - Task cecf3105-81df-11e0-b6a0-525400da69d0: cull_history(, ) missed 1 scheduled runs
2011-05-19 11:48:26,892 [ERROR][Dummy-2] clear_all_sync_in_progress() @ repo.py:73 - r = SON([(u'_id', u'rhui-1.2-5Server-x86_64'), (u'id', u'rhui-1.2-5Server-x86_64'), (u'sync_in_progress', False)])
2011-05-19 11:48:26,892 [ERROR][Dummy-2] clear_all_sync_in_progress() @ repo.py:73 - r = SON([(u'_id', u'rhui-1.2-5Server-i386'), (u'id', u'rhui-1.2-5Server-i386'), (u'sync_in_progress', False)])
2011-05-19 11:48:26,893 [ERROR][Dummy-2] clear_all_sync_in_progress() @ repo.py:73 - r = SON([(u'_id', u'repo157'), (u'id', u'repo157'), (u'sync_in_progress', False)])
2011-05-19 11:48:26,893 [ERROR][Dummy-2] clear_all_sync_in_progress() @ repo.py:73 - r = SON([(u'_id', u'rhui-1.1-5Server-x86_64'), (u'id', u'rhui-1.1-5Server-x86_64'), (u'sync_in_progress', False)])
2011-05-19 11:48:26,894 [ERROR][Dummy-2] clear_all_sync_in_progress() @ repo.py:73 - r = SON([(u'_id', u'rhui-1.1-5Server-i386'), (u'id', u'rhui-1.1-5Server-i386'), (u'sync_in_progress', False)])
2011-05-19 11:48:26,894 [ERROR][Dummy-2] clear_all_sync_in_progress() @ repo.py:73 - r = SON([(u'_id', u'rhel-server-6-updates-6Server-x86_64'), (u'id', u'rhel-server-6-updates-6Server-x86_64'), (u'sync_in_progress', True)])
2011-05-19 11:48:26,895 [ERROR][Dummy-2] clear_all_sync_in_progress() @ repo.py:73 - r = SON([(u'_id', u'rhel-server-6-releases-6Server-x86_64'), (u'id', u'rhel-server-6-releases-6Server-x86_64'), (u'sync_in_progress', True)])
2011-05-19 11:48:26,970 [WARNING][Dummy-2] schedule() @ task.py:192 - Task cee1acbd-81df-11e0-b71a-525400da69d0: RepoApi._sync(rhui-1.2-5Server-x86_64, synchronizer=<pulp.server.api.repo_sync.YumSynchronizer object at 0x7f720d079c10>) missed 1 scheduled runs
2011-05-19 11:48:26,972 [WARNING][Dummy-2] schedule() @ task.py:192 - Task cee1f18a-81df-11e0-b71b-525400da69d0: RepoApi._sync(rhui-1.2-5Server-i386, synchronizer=<pulp.server.api.repo_sync.YumSynchronizer object at 0x7f720d079d90>) missed 1 scheduled runs
^C


Here you can see the "last refreshed" time in the ouput of 'dr' matches with the log's time. So these messages appears immediately when i checked the sync status. 

Also sync was not 'in-progress' state for none of the repos when I checked the status.

Comment 1 wes hayutin 2011-06-06 21:15:30 UTC
added to rhui-20 tracker

Comment 2 Sachin Ghai 2011-06-07 05:10:23 UTC
I'm getting following errors in pulp.log, especially when we login to rhui-manager.

Build:
========
Pulp 0.186
rhui-tools 2.0.26

2011-06-07 10:28:31,866 [ERROR][Dummy-2] clear_all_sync_in_progress() @ repo.py:73 - r = SON([(u'_id', u'repo101'), (u'id', u'repo101'), (u'sync_in_progress', False)])
2011-06-07 10:28:31,866 [ERROR][Dummy-2] clear_all_sync_in_progress() @ repo.py:73 - r = SON([(u'_id', u'rhui-1.2-5Server-x86_64'), (u'id', u'rhui-1.2-5Server-x86_64'), (u'sync_in_progress', False)])
2011-06-07 10:28:31,866 [ERROR][Dummy-2] clear_all_sync_in_progress() @ repo.py:73 - r = SON([(u'_id', u'rhui-1.2-5Server-i386'), (u'id', u'rhui-1.2-5Server-i386'), (u'sync_in_progress', False)])
2011-06-07 10:28:31,867 [ERROR][Dummy-2] clear_all_sync_in_progress() @ repo.py:73 - r = SON([(u'_id', u'rhel-server-6-releases-6Server-x86_64'), (u'id', u'rhel-server-6-releases-6Server-x86_64'), (u'sync_in_progress', True)])
2011-06-07 10:28:31,867 [ERROR][Dummy-2] clear_all_sync_in_progress() @ repo.py:73 - r = SON([(u'_id', u'repo102'), (u'id', u'repo102'), (u'sync_in_progress', False)])
2011-06-07 10:28:31,867 [ERROR][Dummy-2] clear_all_sync_in_progress() @ repo.py:73 - r = SON([(u'_id', u'rhel-server-6-optional-releases-6Server-x86_64'), (u'id', u'rhel-server-6-optional-releases-6Server-x86_64'), (u'sync_in_progress', True)])

We should priortize this to fix in next build.

Comment 3 Jay Dobies 2011-06-22 14:05:17 UTC
Bulk moving a bunch of sync related bugs to ON_QA to test with version 2.0.32.

Comment 4 Sachin Ghai 2011-06-23 08:51:41 UTC
Verified in new build pulp 0.194 and rhui-tools 2.0.32. 

I started sync for multiple repos in parallel and tried to login and logout from rhui-manager several times to reproduce these sync errors in pulp.log. 

These sync errors are not reproducible with this new build. So moving this defect to verified state.

Comment 5 wes hayutin 2011-08-01 21:40:18 UTC
moving to release pending

Comment 6 wes hayutin 2012-05-31 12:56:21 UTC
closing out, product released


Note You need to log in before you can comment on or make changes to this bug.