Setup: - Using RHUI Manager, I set up two repos to sync every three minutes. - The first two times, it worked fine. - On the last, I saw a traceback in pulp.log. Also, RHUI Manager crashed when trying to look up the sync state of the latest task. It looks like it bombed when trying to get the value for the key 'sync_state' in the returned dict from the sync list call. - After another 3 minutes, one repo syncced again successfully. The other (I presume the one that crashed) showed no output in the logs. Traceback on Pulp: 2011-04-20 09:18:00,305 [INFO][Thread-70] _sync() @ repo.py:1483 - Sync of rhui-1.2-5Server-x86_64 starting, skip_dict = {} 2011-04-20 09:18:00,308 [INFO][Thread-71] _sync() @ repo.py:1483 - Sync of rhui-1.2-5Server-i386 starting, skip_dict = {} 2011-04-20 09:18:00,308 [INFO][Thread-70] sync() @ repo_sync.py:447 - Limiting download speed to 0 KB/sec per thread. [15] threads will be used 2011-04-20 09:18:00,309 [INFO][Thread-71] sync() @ repo_sync.py:447 - Limiting download speed to 0 KB/sec per thread. [15] threads will be used 2011-04-20 09:18:03,979 [INFO][Thread-71] sync() @ repo_sync.py:463 - YumSynchronizer reported 13 successes, 0 downloads, 0 errors 2011-04-20 09:18:04,673 [INFO][Thread-70] sync() @ repo_sync.py:463 - YumSynchronizer reported 13 successes, 0 downloads, 0 errors 2011-04-20 09:18:05,297 [INFO][Thread-71] _process_repo_images() @ repo_sync.py:260 - No image files to import to repo.. 2011-04-20 09:18:05,300 [INFO][Thread-71] add_packages_from_dir() @ repo_sync.py:233 - Loaded group info from /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/i386/rhui/1.2/os/repodata/comps-rhel5-server-rhui.xml 2011-04-20 09:18:05,301 [INFO][Thread-71] add_packages_from_dir() @ repo_sync.py:253 - Skipping errata imports from sync process 2011-04-20 09:18:05,301 [INFO][Thread-71] _sync() @ repo.py:1496 - Sync returned 13 packages, 0 errata in 4.99283599854 seconds 2011-04-20 09:18:05,303 [INFO][Thread-71] _sync() @ repo.py:1507 - 0 old packages to process, 0 new packages to process 2011-04-20 09:18:05,311 [INFO][Thread-71] _sync() @ repo.py:1521 - Examining 0 errata from repo rhui-1.2-5Server-i386 2011-04-20 09:18:05,314 [INFO][Thread-71] _sync() @ repo.py:1525 - Removing 0 old errata from repo rhui-1.2-5Server-i386 2011-04-20 09:18:05,321 [INFO][Thread-71] _sync() @ repo.py:1529 - Adding 0 new errata to repo rhui-1.2-5Server-i386 2011-04-20 09:18:05,324 [WARNING][Thread-71] schedule() @ task.py:191 - Task 7525caa8-6b4f-11e0-930f-00508d977dff: RepoApi._sync(rhui-1.2-5Server-i386, synchronizer=<pulp.server.api.repo_sync.YumSynchronizer object at 0x7f990c78c850>) missed 1 scheduled runs 2011-04-20 09:18:05,333 [INFO][Thread-70] _process_repo_images() @ repo_sync.py:260 - No image files to import to repo.. 2011-04-20 09:18:05,334 [INFO][Thread-70] add_packages_from_dir() @ repo_sync.py:233 - Loaded group info from /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/x86_64/rhui/1.2/os/repodata/comps-rhel5-server-rhui.xml 2011-04-20 09:18:05,335 [INFO][Thread-70] add_packages_from_dir() @ repo_sync.py:253 - Skipping errata imports from sync process 2011-04-20 09:18:05,335 [INFO][Thread-70] _sync() @ repo.py:1496 - Sync returned 13 packages, 0 errata in 5.02746105194 seconds 2011-04-20 09:18:05,337 [INFO][Thread-70] _sync() @ repo.py:1507 - 0 old packages to process, 0 new packages to process 2011-04-20 09:18:05,342 [INFO][Thread-70] _sync() @ repo.py:1521 - Examining 0 errata from repo rhui-1.2-5Server-x86_64 2011-04-20 09:18:05,343 [INFO][Thread-70] _sync() @ repo.py:1525 - Removing 0 old errata from repo rhui-1.2-5Server-x86_64 2011-04-20 09:18:05,349 [INFO][Thread-70] _sync() @ repo.py:1529 - Adding 0 new errata to repo rhui-1.2-5Server-x86_64 2011-04-20 09:18:05,351 [ERROR][Thread-70] _complete() @ task.py:325 - Traceback (most recent call last): File "/home/jdob/code/pulp/src/pulp/server/tasking/task.py", line 323, in _complete self.complete_callback(self) File "/home/jdob/code/pulp/src/pulp/server/tasking/taskqueue/queue.py", line 256, in complete self.__storage.remove_running(task) File "/home/jdob/code/pulp/src/pulp/server/tasking/taskqueue/storage.py", line 56, in remove_running assert task in self.__running_tasks AssertionError Logs 3 minutes later (notice it's only got info about one of the repos): 2011-04-20 09:21:00,456 [INFO][Thread-102] _sync() @ repo.py:1483 - Sync of rhui-1.2-5Server-i386 starting, skip_dict = {} 2011-04-20 09:21:00,456 [INFO][Thread-102] sync() @ repo_sync.py:447 - Limiting download speed to 0 KB/sec per thread. [15] threads will be used 2011-04-20 09:21:03,749 [INFO][Thread-102] sync() @ repo_sync.py:463 - YumSynchronizer reported 13 successes, 0 downloads, 0 errors 2011-04-20 09:21:04,409 [INFO][Thread-102] _process_repo_images() @ repo_sync.py:260 - No image files to import to repo.. 2011-04-20 09:21:04,411 [INFO][Thread-102] add_packages_from_dir() @ repo_sync.py:233 - Loaded group info from /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/i386/rhui/1.2/os/repodata/comps-rhel5-server-rhui.xml 2011-04-20 09:21:04,411 [INFO][Thread-102] add_packages_from_dir() @ repo_sync.py:253 - Skipping errata imports from sync process 2011-04-20 09:21:04,412 [INFO][Thread-102] _sync() @ repo.py:1496 - Sync returned 13 packages, 0 errata in 3.9555478096 seconds 2011-04-20 09:21:04,413 [INFO][Thread-102] _sync() @ repo.py:1507 - 0 old packages to process, 0 new packages to process 2011-04-20 09:21:04,418 [INFO][Thread-102] _sync() @ repo.py:1521 - Examining 0 errata from repo rhui-1.2-5Server-i386 2011-04-20 09:21:04,420 [INFO][Thread-102] _sync() @ repo.py:1525 - Removing 0 old errata from repo rhui-1.2-5Server-i386 2011-04-20 09:21:04,426 [INFO][Thread-102] _sync() @ repo.py:1529 - Adding 0 new errata to repo rhui-1.2-5Server-i386 2011-04-20 09:21:04,429 [WARNING][Thread-102] schedule() @ task.py:191 - Task 7525caa8-6b4f-11e0-930f-00508d977dff: RepoApi._sync(rhui-1.2-5Server-i386, synchronizer=<pulp.server.api.repo_sync.YumSynchronizer object at 0x7f990c78c850>) missed 1 scheduled runs
To make this easier to test, install RHUI Manager and edit rhui.tools.pulp_api in the create_redhat_repo method to change the interval from being in hours to minutes: schedule = { # 'interval' : {'hours' : int(sync_frequency_in_hours)}, 'interval' : {'minutes' : 3}, 'start_time': {'year': now.year, 'month': now.month, 'day': now.day, 'hour': now.hour, 'minute': now.minute}, }
Same setup, when I deleted the repo: 011-04-20 11:29:43,766 [INFO][Dummy-5] delete_for_repo() @ repo_cert_utils.py:90 - Deleting certificate bundles at [/etc/pki/content/rhui-1.2-5Server-x86_64] 2011-04-20 11:30:00,363 [ERROR][Thread-790] set_sync_in_progress() @ repo.py:2007 - no repo exists for [rhui-1.2-5Server-i386] 2011-04-20 11:30:00,363 [ERROR][Thread-790] _sync() @ repo.py:1470 - We saw sync was in progress for [rhui-1.2-5Server-i386] 2011-04-20 11:30:00,365 [ERROR][Thread-790] failed() @ task.py:310 - Task id:7525caa8-6b4f-11e0-930f-00508d977dff, method_name:_sync: Traceback (most recent call last): File "/home/jdob/code/pulp/src/pulp/server/tasking/task.py", line 258, in run result = self.callable(*self.args, **self.kwargs) File "/home/jdob/code/pulp/src/pulp/server/api/repo.py", line 1471, in _sync raise ConflictingOperationException() ConflictingOperationException Also saw this later: 2011-04-20 13:00:00,255 [WARNING][Thread-791] schedule() @ task.py:191 - Task 6218744c-6b4f-11e0-9633-00508d977dff: cull_audited_events(, ) missed 1 scheduled runs
I changed some of the logic around "automatically" handling the running task reference when storing a completed task. This I believe, is the cause of the assertion error in the description. This is only fixed in the rhui branch, as the logic is already changed in master.
build: 0.170
Could not verify this defect due to the defect 702334 as "Next Sync' time doesn't change. and because of this the next sync doesn't start at specified interval of time. I changed the sync freqency in minutes as suggested in Comment 1 to sync the repos in every 3 minutes. But didn't see anything in pulp.log. However pulp.log file should be updated in an interval time of 3 minutes. repo sync works as expected when I tried to trigger individual repo sync with 'sr' here are the pulp.log: 2011-05-05 14:09:13,449 [INFO][Dummy-5] sync() @ repositories.py:561 - sync timeout passed : None 2011-05-05 14:09:13,496 [INFO][Thread-70] _sync() @ repo.py:1489 - Sync of rhui-1.2-5Server-i386 starting, skip_dict = {} 2011-05-05 14:09:13,496 [INFO][Thread-70] sync() @ repo_sync.py:447 - Limiting download speed to 0 KB/sec per thread. [15] threads will be used 2011-05-05 14:09:13,674 [INFO][Dummy-2] sync() @ repositories.py:561 - sync timeout passed : None 2011-05-05 14:09:13,709 [INFO][Thread-86] _sync() @ repo.py:1489 - Sync of rhui-1.2-5Server-x86_64 starting, skip_dict = {} 2011-05-05 14:09:13,710 [INFO][Thread-86] sync() @ repo_sync.py:447 - Limiting download speed to 0 KB/sec per thread. [15] threads will be used 2011-05-05 14:09:34,857 [INFO][Thread-70] sync() @ repo_sync.py:463 - YumSynchronizer reported 13 successes, 0 downloads, 0 errors 2011-05-05 14:09:35,246 [INFO][Thread-86] sync() @ repo_sync.py:463 - YumSynchronizer reported 13 successes, 0 downloads, 0 errors 2011-05-05 14:09:35,703 [INFO][Thread-70] _process_repo_images() @ repo_sync.py:260 - No image files to import to repo.. 2011-05-05 14:09:35,705 [INFO][Thread-70] add_packages_from_dir() @ repo_sync.py:233 - Loaded group info from /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/i386/rhui/1.2/os/repodata/comps-rhel5-server-rhui.xml 2011-05-05 14:09:35,708 [INFO][Thread-70] add_packages_from_dir() @ repo_sync.py:253 - Skipping errata imports from sync process 2011-05-05 14:09:35,708 [INFO][Thread-70] _sync() @ repo.py:1502 - Sync returned 13 packages, 0 errata in 22.2118318081 seconds 2011-05-05 14:09:35,712 [INFO][Thread-70] _sync() @ repo.py:1513 - 0 old packages to process, 0 new packages to process 2011-05-05 14:09:35,718 [INFO][Thread-86] _process_repo_images() @ repo_sync.py:260 - No image files to import to repo.. 2011-05-05 14:09:35,721 [INFO][Thread-70] _sync() @ repo.py:1527 - Examining 0 errata from repo rhui-1.2-5Server-i386 2011-05-05 14:09:35,722 [INFO][Thread-86] add_packages_from_dir() @ repo_sync.py:233 - Loaded group info from /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/x86_64/rhui/1.2/os/repodata/comps-rhel5-server-rhui.xml 2011-05-05 14:09:35,722 [INFO][Thread-86] add_packages_from_dir() @ repo_sync.py:253 - Skipping errata imports from sync process 2011-05-05 14:09:35,724 [INFO][Thread-86] _sync() @ repo.py:1502 - Sync returned 13 packages, 0 errata in 22.0145659447 seconds 2011-05-05 14:09:35,724 [INFO][Thread-70] _sync() @ repo.py:1531 - Removing 0 old errata from repo rhui-1.2-5Server-i386 2011-05-05 14:09:35,730 [INFO][Thread-86] _sync() @ repo.py:1513 - 0 old packages to process, 0 new packages to process 2011-05-05 14:09:35,736 [INFO][Thread-86] _sync() @ repo.py:1527 - Examining 0 errata from repo rhui-1.2-5Server-x86_64 2011-05-05 14:09:35,739 [INFO][Thread-86] _sync() @ repo.py:1531 - Removing 0 old errata from repo rhui-1.2-5Server-x86_64 2011-05-05 14:09:35,738 [INFO][Thread-70] _sync() @ repo.py:1535 - Adding 0 new errata to repo rhui-1.2-5Server-i386 2011-05-05 14:09:35,748 [INFO][Thread-86] _sync() @ repo.py:1535 - Adding 0 new errata to repo rhui-1.2-5Server-x86_64 Didn't see any 'assertion' error. I'll verify this defect again, when defect 702334 will be resolved.
Didn't find assertion error or any other traceback during the sync interval of 6 hours.. Please see the logs below: Sync at 18:06 PM ==================== 2011-05-05 18:06:00,006 [INFO][Thread-38] _sync() @ repo.py:1489 - Sync of rhui-1.2-5Server-x86_64 starting, skip_dict = {} 2011-05-05 18:06:00,007 [INFO][Thread-38] sync() @ repo_sync.py:447 - Limiting download speed to 0 KB/sec per thread. [15] threads will be used 2011-05-05 18:06:00,010 [INFO][Thread-39] _sync() @ repo.py:1489 - Sync of rhui-1.2-5Server-i386 starting, skip_dict = {} 2011-05-05 18:06:00,011 [INFO][Thread-39] sync() @ repo_sync.py:447 - Limiting download speed to 0 KB/sec per thread. [15] threads will be used 2011-05-05 18:06:22,599 [INFO][Thread-38] sync() @ repo_sync.py:463 - YumSynchronizer reported 13 successes, 0 downloads, 0 errors 2011-05-05 18:06:23,001 [INFO][Thread-39] sync() @ repo_sync.py:463 - YumSynchronizer reported 13 successes, 0 downloads, 0 errors 2011-05-05 18:06:23,529 [INFO][Thread-38] _process_repo_images() @ repo_sync.py:260 - No image files to import to repo.. 2011-05-05 18:06:23,531 [INFO][Thread-38] add_packages_from_dir() @ repo_sync.py:233 - Loaded group info from /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/x86_64/rhui/1.2/os/repodata/comps-rhel5-server-rhui.xml 2011-05-05 18:06:23,533 [INFO][Thread-38] add_packages_from_dir() @ repo_sync.py:253 - Skipping errata imports from sync process 2011-05-05 18:06:23,534 [INFO][Thread-38] _sync() @ repo.py:1502 - Sync returned 13 packages, 0 errata in 23.5278248787 seconds 2011-05-05 18:06:23,538 [INFO][Thread-38] _sync() @ repo.py:1513 - 0 old packages to process, 0 new packages to process 2011-05-05 18:06:23,543 [INFO][Thread-39] _process_repo_images() @ repo_sync.py:260 - No image files to import to repo.. 2011-05-05 18:06:23,545 [INFO][Thread-39] add_packages_from_dir() @ repo_sync.py:233 - Loaded group info from /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/i386/rhui/1.2/os/repodata/comps-rhel5-server-rhui.xml 2011-05-05 18:06:23,547 [INFO][Thread-39] add_packages_from_dir() @ repo_sync.py:253 - Skipping errata imports from sync process 2011-05-05 18:06:23,547 [INFO][Thread-39] _sync() @ repo.py:1502 - Sync returned 13 packages, 0 errata in 23.5364530087 seconds 2011-05-05 18:06:23,547 [INFO][Thread-38] _sync() @ repo.py:1527 - Examining 0 errata from repo rhui-1.2-5Server-x86_64 2011-05-05 18:06:23,551 [INFO][Thread-38] _sync() @ repo.py:1531 - Removing 0 old errata from repo rhui-1.2-5Server-x86_64 2011-05-05 18:06:23,553 [INFO][Thread-39] _sync() @ repo.py:1513 - 0 old packages to process, 0 new packages to process 2011-05-05 18:06:23,564 [INFO][Thread-39] _sync() @ repo.py:1527 - Examining 0 errata from repo rhui-1.2-5Server-i386 2011-05-05 18:06:23,565 [INFO][Thread-38] _sync() @ repo.py:1535 - Adding 0 new errata to repo rhui-1.2-5Server-x86_64 2011-05-05 18:06:23,567 [INFO][Thread-39] _sync() @ repo.py:1531 - Removing 0 old errata from repo rhui-1.2-5Server-i386 2011-05-05 18:06:23,572 [WARNING][Thread-38] schedule() @ task.py:192 - Task 7bfdd526-7704-11e0-a38c-525400da69d0: RepoApi._sync(rhui-1.2-5Server-x86_64, synchronizer=<pulp.server.api.repo_sync.YumSynchronizer object at 0x7fc0905d1bd0>) missed 1 scheduled runs 2011-05-05 18:06:23,575 [INFO][Thread-39] _sync() @ repo.py:1535 - Adding 0 new errata to repo rhui-1.2-5Server-i386 2011-05-05 18:06:23,578 [WARNING][Thread-39] schedule() @ task.py:192 - Task 7bfe222e-7704-11e0-a38e-525400da69d0: RepoApi._sync(rhui-1.2-5Server-i386, synchronizer=<pulp.server.api.repo_sync.YumSynchronizer object at 0x7fc0905d1bd0>) missed 1 scheduled runs sync at 12:00AM ================ 2011-05-06 00:06:00,324 [INFO][Thread-71] _sync() @ repo.py:1489 - Sync of rhui-1.2-5Server-i386 starting, skip_dict = {} 2011-05-06 00:06:00,296 [INFO][Thread-70] _sync() @ repo.py:1489 - Sync of rhui-1.2-5Server-x86_64 starting, skip_dict = {} 2011-05-06 00:06:00,369 [INFO][Thread-70] sync() @ repo_sync.py:447 - Limiting download speed to 0 KB/sec per thread. [15] threads will be used 2011-05-06 00:06:00,427 [INFO][Thread-71] sync() @ repo_sync.py:447 - Limiting download speed to 0 KB/sec per thread. [15] threads will be used 2011-05-06 00:06:26,336 [INFO][Thread-71] sync() @ repo_sync.py:463 - YumSynchronizer reported 13 successes, 0 downloads, 0 errors 2011-05-06 00:06:26,961 [INFO][Thread-70] sync() @ repo_sync.py:463 - YumSynchronizer reported 13 successes, 0 downloads, 0 errors 2011-05-06 00:06:27,756 [INFO][Thread-71] _process_repo_images() @ repo_sync.py:260 - No image files to import to repo.. 2011-05-06 00:06:27,758 [INFO][Thread-70] _process_repo_images() @ repo_sync.py:260 - No image files to import to repo.. 2011-05-06 00:06:27,766 [INFO][Thread-70] add_packages_from_dir() @ repo_sync.py:233 - Loaded group info from /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/x86_64/rhui/1.2/os/repodata/comps-rhel5-server-rhui.xml 2011-05-06 00:06:27,766 [INFO][Thread-70] add_packages_from_dir() @ repo_sync.py:253 - Skipping errata imports from sync process 2011-05-06 00:06:27,767 [INFO][Thread-70] _sync() @ repo.py:1502 - Sync returned 13 packages, 0 errata in 27.4233891964 seconds 2011-05-06 00:06:27,767 [INFO][Thread-71] add_packages_from_dir() @ repo_sync.py:233 - Loaded group info from /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/i386/rhui/1.2/os/repodata/comps-rhel5-server-rhui.xml 2011-05-06 00:06:27,770 [INFO][Thread-71] add_packages_from_dir() @ repo_sync.py:253 - Skipping errata imports from sync process 2011-05-06 00:06:27,771 [INFO][Thread-71] _sync() @ repo.py:1502 - Sync returned 13 packages, 0 errata in 27.4129850864 seconds 2011-05-06 00:06:27,773 [INFO][Thread-70] _sync() @ repo.py:1513 - 0 old packages to process, 0 new packages to process 2011-05-06 00:06:27,777 [INFO][Thread-71] _sync() @ repo.py:1513 - 0 old packages to process, 0 new packages to process 2011-05-06 00:06:27,782 [INFO][Thread-70] _sync() @ repo.py:1527 - Examining 0 errata from repo rhui-1.2-5Server-x86_64 2011-05-06 00:06:27,786 [INFO][Thread-70] _sync() @ repo.py:1531 - Removing 0 old errata from repo rhui-1.2-5Server-x86_64 2011-05-06 00:06:27,784 [INFO][Thread-71] _sync() @ repo.py:1527 - Examining 0 errata from repo rhui-1.2-5Server-i386 2011-05-06 00:06:27,788 [INFO][Thread-71] _sync() @ repo.py:1531 - Removing 0 old errata from repo rhui-1.2-5Server-i386 2011-05-06 00:06:27,800 [INFO][Thread-70] _sync() @ repo.py:1535 - Adding 0 new errata to repo rhui-1.2-5Server-x86_64 2011-05-06 00:06:27,801 [INFO][Thread-71] _sync() @ repo.py:1535 - Adding 0 new errata to repo rhui-1.2-5Server-i386 2011-05-06 00:06:27,838 [WARNING][Thread-70] schedule() @ task.py:192 - Task 7bfdd526-7704-11e0-a38c-525400da69d0: RepoApi._sync(rhui-1.2-5Server-x86_64, synchronizer=<pulp.server.api.repo_sync.YumSynchronizer object at 0x7fc0905d1bd0>) missed 1 scheduled runs 2011-05-06 00:06:27,838 [WARNING][Thread-71] schedule() @ task.py:192 - Task 7bfe222e-7704-11e0-a38e-525400da69d0: RepoApi._sync(rhui-1.2-5Server-i386, synchronizer=<pulp.server.api.repo_sync.YumSynchronizer object at 0x7fc0905d1bd0>) missed 1 scheduled runs 2011-05-06 01:00:00,448 [WARNING][Thread-102] schedule() @ task.py:192 - Task 7bfd08f8-7704-11e0-a386-525400da69d0: cull_audited_events(, ) missed 1 scheduled runs 2011-05-06 01:00:00,450 [WARNING][Thread-103] schedule() @ task.py:192 - Task 7bfd25cc-7704-11e0-a387-525400da69d0: cull_history(, ) missed 1 scheduled runs sync at 6:00AM ================= 2011-05-06 06:06:00,430 [INFO][Thread-104] _sync() @ repo.py:1489 - Sync of rhui-1.2-5Server-i386 starting, skip_dict = {} 2011-05-06 06:06:00,430 [INFO][Thread-105] _sync() @ repo.py:1489 - Sync of rhui-1.2-5Server-x86_64 starting, skip_dict = {} 2011-05-06 06:06:00,477 [INFO][Thread-105] sync() @ repo_sync.py:447 - Limiting download speed to 0 KB/sec per thread. [15] threads will be used 2011-05-06 06:06:00,481 [INFO][Thread-104] sync() @ repo_sync.py:447 - Limiting download speed to 0 KB/sec per thread. [15] threads will be used 2011-05-06 06:06:25,318 [INFO][Thread-104] sync() @ repo_sync.py:463 - YumSynchronizer reported 13 successes, 0 downloads, 0 errors 2011-05-06 06:06:26,023 [INFO][Thread-105] sync() @ repo_sync.py:463 - YumSynchronizer reported 13 successes, 0 downloads, 0 errors 2011-05-06 06:06:26,840 [INFO][Thread-105] _process_repo_images() @ repo_sync.py:260 - No image files to import to repo.. 2011-05-06 06:06:26,842 [INFO][Thread-105] add_packages_from_dir() @ repo_sync.py:233 - Loaded group info from /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/x86_64/rhui/1.2/os/repodata/comps-rhel5-server-rhui.xml 2011-05-06 06:06:26,844 [INFO][Thread-105] add_packages_from_dir() @ repo_sync.py:253 - Skipping errata imports from sync process 2011-05-06 06:06:26,844 [INFO][Thread-105] _sync() @ repo.py:1502 - Sync returned 13 packages, 0 errata in 26.3676960468 seconds 2011-05-06 06:06:26,844 [INFO][Thread-104] _process_repo_images() @ repo_sync.py:260 - No image files to import to repo.. 2011-05-06 06:06:26,847 [INFO][Thread-104] add_packages_from_dir() @ repo_sync.py:233 - Loaded group info from /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/i386/rhui/1.2/os/repodata/comps-rhel5-server-rhui.xml 2011-05-06 06:06:26,858 [INFO][Thread-104] add_packages_from_dir() @ repo_sync.py:253 - Skipping errata imports from sync process 2011-05-06 06:06:26,858 [INFO][Thread-104] _sync() @ repo.py:1502 - Sync returned 13 packages, 0 errata in 26.3852632046 seconds 2011-05-06 06:06:26,860 [INFO][Thread-104] _sync() @ repo.py:1513 - 0 old packages to process, 0 new packages to process 2011-05-06 06:06:26,865 [INFO][Thread-104] _sync() @ repo.py:1527 - Examining 0 errata from repo rhui-1.2-5Server-i386 2011-05-06 06:06:26,867 [INFO][Thread-104] _sync() @ repo.py:1531 - Removing 0 old errata from repo rhui-1.2-5Server-i386 2011-05-06 06:06:26,870 [INFO][Thread-105] _sync() @ repo.py:1513 - 0 old packages to process, 0 new packages to process 2011-05-06 06:06:26,877 [INFO][Thread-104] _sync() @ repo.py:1535 - Adding 0 new errata to repo rhui-1.2-5Server-i386 2011-05-06 06:06:26,879 [INFO][Thread-105] _sync() @ repo.py:1527 - Examining 0 errata from repo rhui-1.2-5Server-x86_64 2011-05-06 06:06:26,882 [INFO][Thread-105] _sync() @ repo.py:1531 - Removing 0 old errata from repo rhui-1.2-5Server-x86_64 2011-05-06 06:06:26,883 [WARNING][Thread-104] schedule() @ task.py:192 - Task 7bfe222e-7704-11e0-a38e-525400da69d0: RepoApi._sync(rhui-1.2-5Server-i386, synchronizer=<pulp.server.api.repo_sync.YumSynchronizer object at 0x7fc0905d1bd0>) missed 1 scheduled runs 2011-05-06 06:06:26,890 [INFO][Thread-105] _sync() @ repo.py:1535 - Adding 0 new errata to repo rhui-1.2-5Server-x86_64 2011-05-06 06:06:26,892 [WARNING][Thread-105] schedule() @ task.py:192 - Task 7bfdd526-7704-11e0-a38c-525400da69d0: RepoApi._sync(rhui-1.2-5Server-x86_64, synchronizer=<pulp.server.api.repo_sync.YumSynchronizer object at 0x7fc0905d1bd0>) missed 1 scheduled runs
I set two repos to sync in very 1 hour in rhui-tools.conf. but the sync runs at default interval of 6 hours. Earlier sync was running absolutely fine.. but today I got following error in /var/log/pulp/pulp.log. This is the same error as Jason has mentioned in the defect description. 2011-05-11 11:18:33,250 [WARNING][Dummy-5] schedule() @ task.py:192 - Task 4e6fbed4-7b92-11e0-b862-525400da69d0: CdsApi.cds_sync(dhcp193-73.pnq.redhat.com, ) missed 1 scheduled runs 2011-05-11 12:06:00,282 [INFO][Thread-7] _sync() @ repo.py:1489 - Sync of rhui-1.2-5Server-x86_64 starting, skip_dict = {} 2011-05-11 12:06:00,283 [INFO][Thread-7] sync() @ repo_sync.py:447 - Limiting download speed to 0 KB/sec per thread. [15] threads will be used 2011-05-11 12:06:00,288 [INFO][Thread-8] _sync() @ repo.py:1489 - Sync of rhui-1.2-5Server-i386 starting, skip_dict = {} 2011-05-11 12:06:00,288 [INFO][Thread-8] sync() @ repo_sync.py:447 - Limiting download speed to 0 KB/sec per thread. [15] threads will be used 2011-05-11 12:07:19,216 [INFO][Thread-8] sync() @ repo_sync.py:463 - YumSynchronizer reported 13 successes, 0 downloads, 0 errors 2011-05-11 12:07:19,672 [INFO][Thread-8] _process_repo_images() @ repo_sync.py:260 - No image files to import to repo.. 2011-05-11 12:07:19,674 [INFO][Thread-8] add_packages_from_dir() @ repo_sync.py:233 - Loaded group info from /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/i386/rhui/1.2/os/repodata/comps-rhel5-server-rhui.xml 2011-05-11 12:07:19,675 [INFO][Thread-8] add_packages_from_dir() @ repo_sync.py:253 - Skipping errata imports from sync process 2011-05-11 12:07:19,675 [INFO][Thread-8] _sync() @ repo.py:1502 - Sync returned 13 packages, 0 errata in 79.3865420818 seconds 2011-05-11 12:07:19,677 [INFO][Thread-8] _sync() @ repo.py:1513 - 0 old packages to process, 0 new packages to process 2011-05-11 12:07:19,682 [INFO][Thread-8] _sync() @ repo.py:1527 - Examining 0 errata from repo rhui-1.2-5Server-i386 2011-05-11 12:07:19,683 [INFO][Thread-8] _sync() @ repo.py:1531 - Removing 0 old errata from repo rhui-1.2-5Server-i386 2011-05-11 12:07:19,689 [INFO][Thread-8] _sync() @ repo.py:1535 - Adding 0 new errata to repo rhui-1.2-5Server-i386 2011-05-11 12:07:19,692 [WARNING][Thread-8] schedule() @ task.py:192 - Task 40fd365c-7b90-11e0-84cf-525400da69d0: RepoApi._sync(rhui-1.2-5Server-i386, synchronizer=<pulp.server.api.repo_sync.YumSynchronizer object at 0x7f947c5d0b50>) missed 1 scheduled runs 2011-05-11 12:07:20,449 [INFO][Thread-7] sync() @ repo_sync.py:463 - YumSynchronizer reported 13 successes, 0 downloads, 0 errors 2011-05-11 12:07:20,928 [INFO][Thread-7] _process_repo_images() @ repo_sync.py:260 - No image files to import to repo.. 2011-05-11 12:07:20,929 [INFO][Thread-7] add_packages_from_dir() @ repo_sync.py:233 - Loaded group info from /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/x86_64/rhui/1.2/os/repodata/comps-rhel5-server-rhui.xml 2011-05-11 12:07:20,930 [INFO][Thread-7] add_packages_from_dir() @ repo_sync.py:253 - Skipping errata imports from sync process 2011-05-11 12:07:20,930 [INFO][Thread-7] _sync() @ repo.py:1502 - Sync returned 13 packages, 0 errata in 80.6475291252 seconds 2011-05-11 12:07:20,932 [INFO][Thread-7] _sync() @ repo.py:1513 - 0 old packages to process, 0 new packages to process 2011-05-11 12:07:20,937 [INFO][Thread-7] _sync() @ repo.py:1527 - Examining 0 errata from repo rhui-1.2-5Server-x86_64 2011-05-11 12:07:20,938 [INFO][Thread-7] _sync() @ repo.py:1531 - Removing 0 old errata from repo rhui-1.2-5Server-x86_64 2011-05-11 12:07:20,944 [INFO][Thread-7] _sync() @ repo.py:1535 - Adding 0 new errata to repo rhui-1.2-5Server-x86_64 2011-05-11 12:07:20,947 [ERROR][Thread-7] _complete() @ task.py:325 - Traceback (most recent call last): File "/usr/lib/python2.6/site-packages/pulp/server/tasking/task.py", line 323, in _complete self.complete_callback(self) File "/usr/lib/python2.6/site-packages/pulp/server/tasking/taskqueue/queue.py", line 261, in complete self.__storage.remove_running(task) File "/usr/lib/python2.6/site-packages/pulp/server/tasking/taskqueue/storage.py", line 55, in remove_running assert task in self.__running_tasks AssertionError
I'm using following builds.. pulp 0.171 rhui-tools 2.0.22 rpms: ===== pulp-client-0.0.171-1.el6.noarch pulp-0.0.171-1.el6.noarch pulp-common-0.0.171-1.el6.noarch python-gofer-0.33-1.el6.noarch gofer-0.33-1.el6.noarch grinder-0.0.95-1.el6.noarch
This defect is reproducible. I got the same Assertion error in pulp.log. First two times sync ran successfuly and third time I got the traceback in pulp.log. 2011-05-12 06:06:00,053 [INFO][Thread-85] _sync() @ repo.py:1489 - Sync of rhui-1.2-5Server-i386 starting, skip_dict = {} 2011-05-12 06:06:00,053 [INFO][Thread-85] sync() @ repo_sync.py:447 - Limiting download speed to 0 KB/sec per thread. [15] threads will be used 2011-05-12 06:06:00,057 [INFO][Thread-86] _sync() @ repo.py:1489 - Sync of rhui-1.2-5Server-x86_64 starting, skip_dict = {} 2011-05-12 06:06:00,058 [INFO][Thread-86] sync() @ repo_sync.py:447 - Limiting download speed to 0 KB/sec per thread. [15] threads will be used 2011-05-12 06:06:24,042 [INFO][Thread-86] sync() @ repo_sync.py:463 - YumSynchronizer reported 13 successes, 0 downloads, 0 errors 2011-05-12 06:06:24,528 [INFO][Thread-85] sync() @ repo_sync.py:463 - YumSynchronizer reported 13 successes, 0 downloads, 0 errors 2011-05-12 06:06:25,008 [INFO][Thread-86] _process_repo_images() @ repo_sync.py:260 - No image files to import to repo.. 2011-05-12 06:06:25,012 [INFO][Thread-86] add_packages_from_dir() @ repo_sync.py:233 - Loaded group info from /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/x86_64/rhui/1.2/os/repodata/comps-rhel5-server-rhui.xml 2011-05-12 06:06:25,013 [INFO][Thread-86] add_packages_from_dir() @ repo_sync.py:253 - Skipping errata imports from sync process 2011-05-12 06:06:25,014 [INFO][Thread-86] _sync() @ repo.py:1502 - Sync returned 13 packages, 0 errata in 24.9556679726 seconds 2011-05-12 06:06:25,014 [INFO][Thread-85] _process_repo_images() @ repo_sync.py:260 - No image files to import to repo.. 2011-05-12 06:06:25,017 [INFO][Thread-85] add_packages_from_dir() @ repo_sync.py:233 - Loaded group info from /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/i386/rhui/1.2/os/repodata/comps-rhel5-server-rhui.xml 2011-05-12 06:06:25,018 [INFO][Thread-85] add_packages_from_dir() @ repo_sync.py:253 - Skipping errata imports from sync process 2011-05-12 06:06:25,018 [INFO][Thread-85] _sync() @ repo.py:1502 - Sync returned 13 packages, 0 errata in 24.9650259018 seconds 2011-05-12 06:06:25,018 [INFO][Thread-86] _sync() @ repo.py:1513 - 0 old packages to process, 0 new packages to process 2011-05-12 06:06:25,024 [INFO][Thread-85] _sync() @ repo.py:1513 - 0 old packages to process, 0 new packages to process 2011-05-12 06:06:25,028 [INFO][Thread-86] _sync() @ repo.py:1527 - Examining 0 errata from repo rhui-1.2-5Server-x86_64 2011-05-12 06:06:25,031 [INFO][Thread-85] _sync() @ repo.py:1527 - Examining 0 errata from repo rhui-1.2-5Server-i386 2011-05-12 06:06:25,032 [INFO][Thread-86] _sync() @ repo.py:1531 - Removing 0 old errata from repo rhui-1.2-5Server-x86_64 2011-05-12 06:06:25,037 [INFO][Thread-85] _sync() @ repo.py:1531 - Removing 0 old errata from repo rhui-1.2-5Server-i386 2011-05-12 06:06:25,045 [INFO][Thread-86] _sync() @ repo.py:1535 - Adding 0 new errata to repo rhui-1.2-5Server-x86_64 2011-05-12 06:06:25,047 [INFO][Thread-85] _sync() @ repo.py:1535 - Adding 0 new errata to repo rhui-1.2-5Server-i386 2011-05-12 06:06:25,051 [WARNING][Thread-86] schedule() @ task.py:192 - Task 1fa79933-7bbf-11e0-af44-525400da69d0: RepoApi._sync(rhui-1.2-5Server-x86_64, synchronizer=<pulp.server.api.repo_sync.YumSynchronizer object at 0x7ffe4c5d0b10>) missed 1 scheduled runs 2011-05-12 06:06:25,052 [ERROR][Thread-85] _complete() @ task.py:325 - Traceback (most recent call last): File "/usr/lib/python2.6/site-packages/pulp/server/tasking/task.py", line 323, in _complete self.complete_callback(self) File "/usr/lib/python2.6/site-packages/pulp/server/tasking/taskqueue/queue.py", line 261, in complete self.__storage.remove_running(task) File "/usr/lib/python2.6/site-packages/pulp/server/tasking/taskqueue/storage.py", line 55, in remove_running assert task in self.__running_tasks AssertionError Also got "unexpected error" using RHUI-manager. This is when i was trying to check the sync status. [root@dhcp193-136 rhui]# tail -f /root/.rhui/rhui.log Shell.listen(self) File "/usr/lib/python2.6/site-packages/rhui/common/shell.py", line 191, in listen item.func(*args, **item.kwargs) File "/usr/lib/python2.6/site-packages/rhui/tools/screens/sync.py", line 63, in repo_display self._sync_display('-= Repository Synchronization Status =-', self.pulp.repos_with_sync_status, False) File "/usr/lib/python2.6/site-packages/rhui/tools/screens/sync.py", line 241, in _sync_display self.prompt.write(SYNC_STATUS_LINE % (next_sync, render.format_date(data['last_sync']), self._color_sync_state(data))) File "/usr/lib/python2.6/site-packages/rhui/tools/screens/sync.py", line 259, in _color_sync_state return self.prompt.color(data['sync_state'], STATE_COLORS[data['sync_state']]) KeyError: None
This was a bug in the task storage, which has all recently changed, can I get someone to re-verify this bug?
This defect is not reproducible in new build: - pulp 0.186 - rhui-tools 2.0.26 I set the sync interval=1 hour. I pasted the sync logs for 3 repos and for first sync and third sync only. - rhui 1.2 (i386) - rhui 1.2 (x86_64) - RHEL6 option releases (x86_64) Next Sync Last Sync Last Result ------------------------------------------------------------------------------ Red Hat Enterprise Linux Server 6 Optional Releases (RPMs) (6Server-x86_64) 06-08-2011 14:49 06-08-2011 13:58 finished Red Hat Enterprise Linux Server 6 Releases (RPMs) (6Server-i386) 06-08-2011 13:21 Never running Red Hat Enterprise Linux Server 6 Releases (RPMs) (6Server-x86_64) 06-08-2011 13:30 06-06-2011 22:09 running Red Hat Update Infrastructure 1.2 (RPMs) (5Server-i386) 06-08-2011 14:46 06-08-2011 13:49 finished Red Hat Update Infrastructure 1.2 (RPMs) (5Server-x86_64) 06-08-2011 14:46 06-08-2011 13:49 finished <rhui-1.2-5Server-x86_64>: 2011-06-08 14:48:22,502 [INFO][Thread-90] _sync() @ repo_sync.py:212 - Sync invoked for repo <rhui-1.2-5Server-x86_64> 2011-06-08 14:48:22,504 [INFO][Thread-90] _sync() @ repo_sync.py:222 - Sync of rhui-1.2-5Server-x86_64 starting, skip_dict = {} 2011-06-08 14:48:22,505 [INFO][Thread-90] sync() @ synchronizers.py:383 - cacert = </etc/pki/content/rhui-1.2-5Server-x86_64/feed-rhui-1.2-5Server-x86_64.ca>, cert = </etc/pki/content/rhui-1.2-5Server-x86_64/feed-rhui-1.2-5Server-x86_64.cert>, key = </etc/pki/content/rhui-1.2-5Server-x86_64/feed-rhui-1.2-5Server-x86_64.key> 2011-06-08 14:48:22,506 [INFO][Thread-90] sync() @ synchronizers.py:407 - Limiting download speed to 0 KB/sec per thread. [15] threads will be used 2011-06-08 14:48:42,544 [INFO][Thread-90] sync() @ synchronizers.py:427 - Running createrepo, this may take a few minutes to complete. 2011-06-08 14:48:42,546 [INFO][Thread-90] create_repo() @ util.py:375 - metadata found; taking backup. 2011-06-08 14:48:42,548 [INFO][Thread-90] _create_repo() @ util.py:362 - started repo metadata update 2011-06-08 14:48:48,672 [INFO][Thread-90] _create_repo() @ util.py:368 - [createrepo --database --checksum sha256 -g /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/x86_64/rhui/1.2/os/repodata/comps-rhel5-server-rhui.xml --update /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/x86_64/rhui/1.2/os ] on /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/x86_64/rhui/1.2/os finished 2011-06-08 14:48:48,691 [INFO][Thread-90] sync() @ synchronizers.py:441 - Createrepo finished in 6.1458170414 seconds 2011-06-08 14:48:48,691 [INFO][Thread-90] sync() @ synchronizers.py:443 - YumSynchronizer reported 13 successes, 0 downloads, 0 errors 2011-06-08 14:48:49,875 [INFO][Thread-90] _process_repo_images() @ synchronizers.py:197 - No image files to import to repo.. 2011-06-08 14:48:49,900 [INFO][Thread-90] import_metadata() @ synchronizers.py:169 - Loaded group info from /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/x86_64/rhui/1.2/os/repodata/comps-rhel5-server-rhui.xml 2011-06-08 14:48:49,901 [INFO][Thread-90] import_metadata() @ synchronizers.py:189 - Skipping errata imports from sync process 2011-06-08 14:48:49,903 [INFO][Thread-90] _sync() @ repo_sync.py:228 - Sync returned 13 packages, 0 errata in 27.3993220329 seconds 2011-06-08 14:48:49,905 [INFO][Thread-90] _sync() @ repo_sync.py:239 - 0 old packages to process, 0 new packages to process 2011-06-08 14:48:49,910 [INFO][Thread-90] _sync() @ repo_sync.py:254 - Examining 0 errata from repo rhui-1.2-5Server-x86_64 2011-06-08 14:48:49,912 [INFO][Thread-90] _sync() @ repo_sync.py:258 - Removing 0 old errata from repo rhui-1.2-5Server-x86_64 2011-06-08 14:48:49,919 [INFO][Thread-90] _sync() @ repo_sync.py:267 - Adding 0 new errata to repo rhui-1.2-5Server-x86_64 <rhui-1.2-5Server-x86_64>: 2011-06-08 14:48:49,959 [INFO][Thread-106] _sync() @ repo_sync.py:212 - Sync invoked for repo <rhui-1.2-5Server-i386> 2011-06-08 14:48:49,962 [INFO][Thread-106] _sync() @ repo_sync.py:222 - Sync of rhui-1.2-5Server-i386 starting, skip_dict = {} 2011-06-08 14:48:49,965 [INFO][Thread-106] sync() @ synchronizers.py:383 - cacert = </etc/pki/content/rhui-1.2-5Server-i386/feed-rhui-1.2-5Server-i386.ca>, cert = </etc/pki/content/rhui-1.2-5Server-i386/feed-rhui-1.2-5Server-i386.cert>, key = </etc/pki/content/rhui-1.2-5Server-i386/feed-rhui-1.2-5Server-i386.key> 2011-06-08 14:48:49,965 [INFO][Thread-106] sync() @ synchronizers.py:407 - Limiting download speed to 0 KB/sec per thread. [15] threads will be used 2011-06-08 14:49:07,856 [INFO][Thread-106] sync() @ synchronizers.py:427 - Running createrepo, this may take a few minutes to complete. 2011-06-08 14:49:07,858 [INFO][Thread-106] create_repo() @ util.py:375 - metadata found; taking backup. 2011-06-08 14:49:07,860 [INFO][Thread-106] _create_repo() @ util.py:362 - started repo metadata update 2011-06-08 14:49:11,413 [INFO][Thread-106] _create_repo() @ util.py:368 - [createrepo --database --checksum sha256 -g /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/i386/rhui/1.2/os/repodata/comps-rhel5-server-rhui.xml --update /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/i386/rhui/1.2/os ] on /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/i386/rhui/1.2/os finished 2011-06-08 14:49:11,415 [INFO][Thread-106] sync() @ synchronizers.py:441 - Createrepo finished in 3.55844807625 seconds 2011-06-08 14:49:11,415 [INFO][Thread-106] sync() @ synchronizers.py:443 - YumSynchronizer reported 13 successes, 0 downloads, 0 errors 2011-06-08 14:49:11,988 [INFO][Thread-106] _process_repo_images() @ synchronizers.py:197 - No image files to import to repo.. 2011-06-08 14:49:11,993 [INFO][Thread-106] import_metadata() @ synchronizers.py:169 - Loaded group info from /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/i386/rhui/1.2/os/repodata/comps-rhel5-server-rhui.xml 2011-06-08 14:49:11,994 [INFO][Thread-106] import_metadata() @ synchronizers.py:189 - Skipping errata imports from sync process 2011-06-08 14:49:11,996 [INFO][Thread-106] _sync() @ repo_sync.py:228 - Sync returned 13 packages, 0 errata in 22.0336649418 seconds 2011-06-08 14:49:11,998 [INFO][Thread-106] _sync() @ repo_sync.py:239 - 0 old packages to process, 0 new packages to process 2011-06-08 14:49:12,003 [INFO][Thread-106] _sync() @ repo_sync.py:254 - Examining 0 errata from repo rhui-1.2-5Server-i386 2011-06-08 14:49:12,005 [INFO][Thread-106] _sync() @ repo_sync.py:258 - Removing 0 old errata from repo rhui-1.2-5Server-i386 2011-06-08 14:49:12,013 [INFO][Thread-106] _sync() @ repo_sync.py:267 - Adding 0 new errata to repo rhui-1.2-5Server-i386 <rhel-server-6-optional-releases-6Server-x86_64>: 2011-06-08 14:49:53,050 [INFO][Thread-122] _sync() @ repo_sync.py:212 - Sync invoked for repo <rhel-server-6-optional-releases-6Server-x86_64> 2011-06-08 14:49:53,073 [INFO][Thread-122] _sync() @ repo_sync.py:222 - Sync of rhel-server-6-optional-releases-6Server-x86_64 starting, skip_dict = {} 2011-06-08 14:49:53,082 [INFO][Thread-122] sync() @ synchronizers.py:383 - cacert = </etc/pki/content/rhel-server-6-optional-releases-6Server-x86_64/feed-rhel-server-6-optional-releases-6Server-x86_64.ca>, cert = </etc/pki/content/rhel-server-6-optional-releases-6Server-x86_64/feed-rhel-server-6-optional-releases-6Server-x86_64.cert>, key = </etc/pki/content/rhel-server-6-optional-releases-6Server-x86_64/feed-rhel-server-6-optional-releases-6Server-x86_64.key> 2011-06-08 14:49:53,083 [INFO][Thread-122] sync() @ synchronizers.py:407 - Limiting download speed to 0 KB/sec per thread. [15] threads will be used 2011-06-08 14:53:44,735 [INFO][Thread-122] sync() @ synchronizers.py:427 - Running createrepo, this may take a few minutes to complete. 2011-06-08 14:53:44,737 [INFO][Thread-122] create_repo() @ util.py:375 - metadata found; taking backup. 2011-06-08 14:53:44,751 [INFO][Thread-122] _create_repo() @ util.py:362 - started repo metadata update 2011-06-08 14:59:07,883 [INFO][Thread-122] _create_repo() @ util.py:368 - [createrepo --database --checksum sha256 -g /var/lib/pulp//repos/content/dist/rhel/rhui/server-6/releases/6Server/x86_64/optional/os/repodata/e6d289eca64761ec25a00ba4429f40aedb36c31ae89ed57f0fe648cf2e2fdfdd-comps-rhel6-Server-optional.xml --update /var/lib/pulp//repos/content/dist/rhel/rhui/server-6/releases/6Server/x86_64/optional/os ] on /var/lib/pulp//repos/content/dist/rhel/rhui/server-6/releases/6Server/x86_64/optional/os finished 2011-06-08 14:59:09,580 [INFO][Thread-122] sync() @ synchronizers.py:441 - Createrepo finished in 324.817782164 seconds 2011-06-08 14:59:09,591 [INFO][Thread-122] sync() @ synchronizers.py:443 - YumSynchronizer reported 2593 successes, 0 downloads, 0 errors 2011-06-08 14:59:50,091 [INFO][Thread-122] _process_repo_images() @ synchronizers.py:197 - No image files to import to repo.. 2011-06-08 14:59:50,127 [INFO][Thread-122] import_metadata() @ synchronizers.py:169 - Loaded group info from /var/lib/pulp//repos/content/dist/rhel/rhui/server-6/releases/6Server/x86_64/optional/os/repodata/e6d289eca64761ec25a00ba4429f40aedb36c31ae89ed57f0fe648cf2e2fdfdd-comps-rhel6-Server-optional.xml 2011-06-08 14:59:50,128 [INFO][Thread-122] import_metadata() @ synchronizers.py:189 - Skipping errata imports from sync process 2011-06-08 14:59:50,150 [INFO][Thread-122] _sync() @ repo_sync.py:228 - Sync returned 2593 packages, 0 errata in 597.076791048 seconds 2011-06-08 14:59:50,196 [INFO][Thread-122] _sync() @ repo_sync.py:239 - 0 old packages to process, 0 new packages to process 2011-06-08 14:59:50,236 [INFO][Thread-122] _sync() @ repo_sync.py:254 - Examining 0 errata from repo rhel-server-6-optional-releases-6Server-x86_64 2011-06-08 14:59:50,244 [INFO][Thread-122] _sync() @ repo_sync.py:258 - Removing 0 old errata from repo rhel-server-6-optional-releases-6Server-x86_64 2011-06-08 14:59:50,289 [INFO][Thread-122] _sync() @ repo_sync.py:267 - Adding 0 new errata to repo rhel-server-6-optional-releases-6Server-x86_64
third sync: No assertion error. =========== 2011-06-08 16:46:41,049 [INFO][Thread-25] _sync() @ repo_sync.py:212 - Sync invoked for repo <rhui-1.2-5Server-x86_64> 2011-06-08 16:46:41,051 [INFO][Thread-25] _sync() @ repo_sync.py:222 - Sync of rhui-1.2-5Server-x86_64 starting, skip_dict = {} 2011-06-08 16:46:41,053 [INFO][Thread-25] sync() @ synchronizers.py:383 - cacert = </etc/pki/content/rhui-1.2-5Server-x86_64/feed-rhui-1.2-5Server-x86_64.ca>, cert = </etc/pki/content/rhui-1.2-5Server-x86_64/feed-rhui-1.2-5Server-x86_64.cert>, key = </etc/pki/content/rhui-1.2-5Server-x86_64/feed-rhui-1.2-5Server-x86_64.key> 2011-06-08 16:46:41,053 [INFO][Thread-25] sync() @ synchronizers.py:407 - Limiting download speed to 0 KB/sec per thread. [15] threads will be used 2011-06-08 16:46:45,678 [INFO][Thread-41] _sync() @ repo_sync.py:212 - Sync invoked for repo <rhui-1.2-5Server-i386> 2011-06-08 16:46:45,680 [INFO][Thread-41] _sync() @ repo_sync.py:222 - Sync of rhui-1.2-5Server-i386 starting, skip_dict = {} 2011-06-08 16:46:45,682 [INFO][Thread-41] sync() @ synchronizers.py:383 - cacert = </etc/pki/content/rhui-1.2-5Server-i386/feed-rhui-1.2-5Server-i386.ca>, cert = </etc/pki/content/rhui-1.2-5Server-i386/feed-rhui-1.2-5Server-i386.cert>, key = </etc/pki/content/rhui-1.2-5Server-i386/feed-rhui-1.2-5Server-i386.key> 2011-06-08 16:46:45,682 [INFO][Thread-41] sync() @ synchronizers.py:407 - Limiting download speed to 0 KB/sec per thread. [15] threads will be used 2011-06-08 16:47:14,394 [INFO][Thread-25] sync() @ synchronizers.py:427 - Running createrepo, this may take a few minutes to complete. 2011-06-08 16:47:14,396 [INFO][Thread-25] create_repo() @ util.py:375 - metadata found; taking backup. 2011-06-08 16:47:14,398 [INFO][Thread-25] _create_repo() @ util.py:362 - started repo metadata update 2011-06-08 16:47:14,613 [INFO][Thread-41] sync() @ synchronizers.py:427 - Running createrepo, this may take a few minutes to complete. 2011-06-08 16:47:14,614 [INFO][Thread-41] create_repo() @ util.py:375 - metadata found; taking backup. 2011-06-08 16:47:14,616 [INFO][Thread-41] _create_repo() @ util.py:362 - started repo metadata update 2011-06-08 16:47:31,903 [INFO][Thread-41] _create_repo() @ util.py:368 - [createrepo --database --checksum sha256 -g /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/i386/rhui/1.2/os/repodata/comps-rhel5-server-rhui.xml --update /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/i386/rhui/1.2/os ] on /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/i386/rhui/1.2/os finished 2011-06-08 16:47:31,905 [INFO][Thread-41] sync() @ synchronizers.py:441 - Createrepo finished in 17.2920300961 seconds 2011-06-08 16:47:31,905 [INFO][Thread-41] sync() @ synchronizers.py:443 - YumSynchronizer reported 13 successes, 0 downloads, 0 errors 2011-06-08 16:47:31,924 [INFO][Thread-25] _create_repo() @ util.py:368 - [createrepo --database --checksum sha256 -g /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/x86_64/rhui/1.2/os/repodata/comps-rhel5-server-rhui.xml --update /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/x86_64/rhui/1.2/os ] on /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/x86_64/rhui/1.2/os finished 2011-06-08 16:47:31,925 [INFO][Thread-25] sync() @ synchronizers.py:441 - Createrepo finished in 17.5303092003 seconds 2011-06-08 16:47:31,925 [INFO][Thread-25] sync() @ synchronizers.py:443 - YumSynchronizer reported 13 successes, 0 downloads, 0 errors 2011-06-08 16:47:41,100 [INFO][Thread-25] _process_repo_images() @ synchronizers.py:197 - No image files to import to repo.. 2011-06-08 16:47:41,103 [INFO][Thread-41] _process_repo_images() @ synchronizers.py:197 - No image files to import to repo.. 2011-06-08 16:47:41,108 [INFO][Thread-25] import_metadata() @ synchronizers.py:169 - Loaded group info from /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/x86_64/rhui/1.2/os/repodata/comps-rhel5-server-rhui.xml 2011-06-08 16:47:41,112 [INFO][Thread-25] import_metadata() @ synchronizers.py:189 - Skipping errata imports from sync process 2011-06-08 16:47:41,111 [INFO][Thread-41] import_metadata() @ synchronizers.py:169 - Loaded group info from /var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/i386/rhui/1.2/os/repodata/comps-rhel5-server-rhui.xml 2011-06-08 16:47:41,114 [INFO][Thread-41] import_metadata() @ synchronizers.py:189 - Skipping errata imports from sync process 2011-06-08 16:47:41,116 [INFO][Thread-25] _sync() @ repo_sync.py:228 - Sync returned 13 packages, 0 errata in 60.0647439957 seconds 2011-06-08 16:47:41,118 [INFO][Thread-25] _sync() @ repo_sync.py:239 - 0 old packages to process, 0 new packages to process 2011-06-08 16:47:41,118 [INFO][Thread-41] _sync() @ repo_sync.py:228 - Sync returned 13 packages, 0 errata in 55.4378499985 seconds 2011-06-08 16:47:41,120 [INFO][Thread-41] _sync() @ repo_sync.py:239 - 0 old packages to process, 0 new packages to process 2011-06-08 16:47:41,127 [INFO][Thread-25] _sync() @ repo_sync.py:254 - Examining 0 errata from repo rhui-1.2-5Server-x86_64 2011-06-08 16:47:41,130 [INFO][Thread-25] _sync() @ repo_sync.py:258 - Removing 0 old errata from repo rhui-1.2-5Server-x86_64 2011-06-08 16:47:41,129 [INFO][Thread-41] _sync() @ repo_sync.py:254 - Examining 0 errata from repo rhui-1.2-5Server-i386 2011-06-08 16:47:41,132 [INFO][Thread-41] _sync() @ repo_sync.py:258 - Removing 0 old errata from repo rhui-1.2-5Server-i386 2011-06-08 16:47:41,142 [INFO][Thread-25] _sync() @ repo_sync.py:267 - Adding 0 new errata to repo rhui-1.2-5Server-x86_64 2011-06-08 16:47:41,143 [INFO][Thread-41] _sync() @ repo_sync.py:267 - Adding 0 new errata to repo rhui-1.2-5Server-i386 2011-06-08 16:49:53,132 [INFO][Thread-57] _sync() @ repo_sync.py:222 - Sync of rhel-server-6-optional-releases-6Server-x86_64 starting, skip_dict = {} 2011-06-08 16:49:53,142 [INFO][Thread-57] sync() @ synchronizers.py:383 - cacert = </etc/pki/content/rhel-server-6-optional-releases-6Server-x86_64/feed-rhel-server-6-optional-releases-6Server-x86_64.ca>, cert = </etc/pki/content/rhel-server-6-optional-releases-6Server-x86_64/feed-rhel-server-6-optional-releases-6Server-x86_64.cert>, key = </etc/pki/content/rhel-server-6-optional-releases-6Server-x86_64/feed-rhel-server-6-optional-releases-6Server-x86_64.key> 2011-06-08 16:49:53,142 [INFO][Thread-57] sync() @ synchronizers.py:407 - Limiting download speed to 0 KB/sec per thread. [15] threads will be used 2011-06-08 16:52:42,976 [INFO][Thread-57] sync() @ synchronizers.py:427 - Running createrepo, this may take a few minutes to complete. 2011-06-08 16:52:42,978 [INFO][Thread-57] create_repo() @ util.py:375 - metadata found; taking backup. 2011-06-08 16:52:43,023 [INFO][Thread-57] _create_repo() @ util.py:362 - started repo metadata update Since this defect is not reprodcible as of now, so moving it to verified state.
Closing with Community Release 15 pulp-0.0.223-4.