Bug 713775 - Error during sync: SQLite objects created in a thread can only be used in that same thread
Summary: Error during sync: SQLite objects created in a thread can only be used in tha...
Keywords:
Status: CLOSED WORKSFORME
Alias: None
Product: Pulp
Classification: Retired
Component: z_other
Version: unspecified
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
: Sprint 26
Assignee: John Matthews
QA Contact: Preethi Thomas
URL:
Whiteboard:
Depends On:
Blocks: 688298
TreeView+ depends on / blocked
 
Reported: 2011-06-16 14:29 UTC by Jay Dobies
Modified: 2011-07-15 19:38 UTC (History)
1 user (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2011-07-15 15:39:22 UTC
Embargoed:


Attachments (Terms of Use)

Description Jay Dobies 2011-06-16 14:29:04 UTC
Refiled from RHUI 704960:

Multiple repos were scheduled to sync and in the time gap of few minutes. 

When scheduled sync starts for more than one repo, it throws an RepoError:

2011-05-16 12:32:06,631 [ERROR][Thread-72] failed() @ task.py:310 - Task
id:06910602-7f81-11e0-9b07-525400da69d0, method_name:_sync:
Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/pulp/server/tasking/task.py", line
258, in run
    result = self.callable(*self.args, **self.kwargs)
  File "/usr/lib/python2.6/site-packages/pulp/server/api/repo.py", line 1499,
in _sync
    threads)
  File "/usr/lib/python2.6/site-packages/pulp/server/api/repo_sync.py", line
146, in sync
    progress_callback, max_speed, threads)
  File "/usr/lib/python2.6/site-packages/pulp/server/api/repo_sync.py", line
460, in sync
    report = self.yum_repo_grinder.fetchYumRepo(store_path,
callback=progress_callback)
  File "/usr/lib/python2.6/site-packages/grinder/RepoFetch.py", line 366, in
fetchYumRepo
    self.prepareRPMS()
  File "/usr/lib/python2.6/site-packages/grinder/RepoFetch.py", line 244, in
prepareRPMS
    info['downloadurl'] = self.yumFetch.repourl + '/' + pkg.relativepath
  File "/usr/lib/python2.6/site-packages/yum/sqlitesack.py", line 268, in
__getattr__
    (self.pkgId,)).fetchone()
  File "/usr/lib/python2.6/site-packages/yum/sqlitesack.py", line 55, in
newFunc
    raise Errors.RepoError, str(e)
RepoError: SQLite objects created in a thread can only be used in that same
thread.The object was created in thread id 140370933417744 and this is thread
id 140370964887312


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

How reproducible:
Observe this only in case of mutiple syncs.

Steps to Reproduce:
1.
2.
3.

Actual results:
Got above traceback with following error:

RepoError: SQLite objects created in a thread can only be used in that same
thread.The object was created in thread id 140370933417744 and this is thread
id 140370964887312

Expected results:
sync should be successfull for all repos.

Additional info:

Here is the scheduled sync status ( Output of "dr")
-= Repository Synchronization Status =-

Last Refreshed: 11:25:35
(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-16-2011 12:24             05-13-2011 18:31             scheduled  

Red Hat Enterprise Linux Server 6 Updates (RPMs) (6Server-x86_64)
05-16-2011 12:26             05-13-2011 18:08             scheduled  

Red Hat Update Infrastructure 1.1 (RPMs) (5Server-i386)
05-16-2011 12:32             05-13-2011 19:06             scheduled  

Red Hat Update Infrastructure 1.1 (RPMs) (5Server-x86_64)
05-16-2011 12:32             05-13-2011 14:02             scheduled  

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

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



Logs when sync starts at 12:6  (Success )
================================
2011-05-16 12:06:00,395 [INFO][Thread-6] _sync() @ repo.py:1489 - Sync of
rhui-1.2-5Server-x86_64 starting, skip_dict = {}
2011-05-16 12:06:00,397 [INFO][Thread-6] sync() @ repo_sync.py:447 - Limiting
download speed to 0 KB/sec per thread. [15] threads will be used
2011-05-16 12:06:00,399 [INFO][Thread-7] _sync() @ repo.py:1489 - Sync of
rhui-1.2-5Server-i386 starting, skip_dict = {}
2011-05-16 12:06:00,400 [INFO][Thread-7] sync() @ repo_sync.py:447 - Limiting
download speed to 0 KB/sec per thread. [15] threads will be used
2011-05-16 12:06:22,304 [INFO][Thread-7] sync() @ repo_sync.py:463 -
YumSynchronizer reported 13 successes, 0 downloads, 0 errors
2011-05-16 12:06:22,728 [INFO][Thread-6] sync() @ repo_sync.py:463 -
YumSynchronizer reported 13 successes, 0 downloads, 0 errors
2011-05-16 12:06:23,772 [INFO][Thread-7] _process_repo_images() @
repo_sync.py:260 - No image files to import to repo..
2011-05-16 12:06:23,774 [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/i386/rhui/1.2/os/repodata/comps-rhel5-server-rhui.xml
2011-05-16 12:06:23,775 [INFO][Thread-6] _process_repo_images() @
repo_sync.py:260 - No image files to import to repo..
2011-05-16 12:06:23,776 [INFO][Thread-6] 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-16 12:06:23,777 [INFO][Thread-6] add_packages_from_dir() @
repo_sync.py:253 - Skipping errata imports from sync process
2011-05-16 12:06:23,777 [INFO][Thread-6] _sync() @ repo.py:1502 - Sync returned
13 packages, 0 errata in 23.3808839321 seconds
2011-05-16 12:06:23,777 [INFO][Thread-7] add_packages_from_dir() @
repo_sync.py:253 - Skipping errata imports from sync process
2011-05-16 12:06:23,779 [INFO][Thread-7] _sync() @ repo.py:1502 - Sync returned
13 packages, 0 errata in 23.3797521591 seconds
2011-05-16 12:06:23,794 [INFO][Thread-7] _sync() @ repo.py:1513 - 0 old
packages to process, 0 new packages to process
2011-05-16 12:06:23,795 [INFO][Thread-6] _sync() @ repo.py:1513 - 0 old
packages to process, 0 new packages to process
2011-05-16 12:06:23,802 [INFO][Thread-7] _sync() @ repo.py:1527 - Examining 0
errata from repo rhui-1.2-5Server-i386
2011-05-16 12:06:23,804 [INFO][Thread-6] _sync() @ repo.py:1527 - Examining 0
errata from repo rhui-1.2-5Server-x86_64
2011-05-16 12:06:23,807 [INFO][Thread-6] _sync() @ repo.py:1531 - Removing 0
old errata from repo rhui-1.2-5Server-x86_64
2011-05-16 12:06:23,805 [INFO][Thread-7] _sync() @ repo.py:1531 - Removing 0
old errata from repo rhui-1.2-5Server-i386
2011-05-16 12:06:23,817 [INFO][Thread-6] _sync() @ repo.py:1535 - Adding 0 new
errata to repo rhui-1.2-5Server-x86_64
2011-05-16 12:06:23,818 [INFO][Thread-7] _sync() @ repo.py:1535 - Adding 0 new
errata to repo rhui-1.2-5Server-i386
2011-05-16 12:06:23,823 [WARNING][Thread-6] schedule() @ task.py:192 - Task
06905ec7-7f81-11e0-9b02-525400da69d0: RepoApi._sync(rhui-1.2-5Server-x86_64,
synchronizer=<pulp.server.api.repo_sync.YumSynchronizer object at
0x7faac45d1ed0>) missed 1 scheduled runs
2011-05-16 12:06:23,823 [WARNING][Thread-7] schedule() @ task.py:192 - Task
0690ab8a-7f81-11e0-9b04-525400da69d0: RepoApi._sync(rhui-1.2-5Server-i386,
synchronizer=<pulp.server.api.repo_sync.YumSynchronizer object at
0x7faac45d1ed0>) missed 1 scheduled runs


Logs when sync starts at 12:24, 12:26 and 12:32  (Traceback)
=====================================================
2011-05-16 12:24:00,623 [INFO][Thread-39] _sync() @ repo.py:1489 - Sync of
rhel-server-6-releases-6Server-x86_64 starting, skip_dict = {}
2011-05-16 12:24:00,623 [INFO][Thread-39] sync() @ repo_sync.py:447 - Limiting
download speed to 0 KB/sec per thread. [15] threads will be used
2011-05-16 12:26:00,932 [INFO][Thread-55] _sync() @ repo.py:1489 - Sync of
rhel-server-6-updates-6Server-x86_64 starting, skip_dict = {}
2011-05-16 12:26:00,932 [INFO][Thread-55] sync() @ repo_sync.py:447 - Limiting
download speed to 0 KB/sec per thread. [15] threads will be used
2011-05-16 12:30:48,804 [INFO][Thread-55] sync() @ repo_sync.py:463 -
YumSynchronizer reported 3994 successes, 0 downloads, 0 errors
2011-05-16 12:31:03,776 [INFO][Thread-55] _process_repo_images() @
repo_sync.py:260 - No image files to import to repo..
2011-05-16 12:31:04,012 [INFO][Thread-55] add_packages_from_dir() @
repo_sync.py:233 - Loaded group info from
/var/lib/pulp//repos/content/dist/rhel/rhui/server-6/updates/6Server/x86_64/os/repodata/comps-rhel-x86_64-server-6.xml
2011-05-16 12:31:04,014 [INFO][Thread-55] add_packages_from_dir() @
repo_sync.py:248 - updateinfo is found in repomd.xml, it's path is
/var/lib/pulp//repos/content/dist/rhel/rhui/server-6/updates/6Server/x86_64/os/repodata/713850e8a4ffefc82e6b6842cede0bc0c6bb04576ae0ff08b6ba4728edf9426f-updateinfo.xml.gz
2011-05-16 12:31:04,319 [INFO][Thread-55] _sync() @ repo.py:1502 - Sync
returned 3994 packages, 143 errata in 303.386878967 seconds
2011-05-16 12:31:04,664 [INFO][Thread-55] _sync() @ repo.py:1513 - 0 old
packages to process, 0 new packages to process
2011-05-16 12:31:05,356 [INFO][Thread-55] _sync() @ repo.py:1527 - Examining
143 errata from repo rhel-server-6-updates-6Server-x86_64
2011-05-16 12:31:05,563 [INFO][Thread-55] _sync() @ repo.py:1531 - Removing 0
old errata from repo rhel-server-6-updates-6Server-x86_64
2011-05-16 12:31:06,582 [INFO][Thread-55] generate_updateinfo() @
updateinfo.py:157 - updateinfo.xml generated and written to file
/var/lib/pulp//repos/content/dist/rhel/rhui/server-6/updates/6Server/x86_64/os//updateinfo.xml
2011-05-16 12:31:08,484 [INFO][Thread-55] modify_repo() @ util.py:378 -
modifyrepo with
/var/lib/pulp//repos/content/dist/rhel/rhui/server-6/updates/6Server/x86_64/os//updateinfo.xml
on
/var/lib/pulp//repos/content/dist/rhel/rhui/server-6/updates/6Server/x86_64/os/repodata
finished
2011-05-16 12:31:08,690 [INFO][Thread-55] _sync() @ repo.py:1535 - Adding 0 new
errata to repo rhel-server-6-updates-6Server-x86_64
2011-05-16 12:31:08,967 [WARNING][Thread-55] schedule() @ task.py:192 - Task
06aea838-7f81-11e0-9bc9-525400da69d0:
RepoApi._sync(rhel-server-6-updates-6Server-x86_64,
synchronizer=<pulp.server.api.repo_sync.YumSynchronizer object at
0x7faac45d1ed0>) missed 1 scheduled runs


2011-05-16 12:32:00,540 [INFO][Thread-71] _sync() @ repo.py:1489 - Sync of
rhui-1.1-5Server-i386 starting, skip_dict = {}
2011-05-16 12:32:00,540 [INFO][Thread-71] sync() @ repo_sync.py:447 - Limiting
download speed to 0 KB/sec per thread. [15] threads will be used
2011-05-16 12:32:00,549 [INFO][Thread-72] _sync() @ repo.py:1489 - Sync of
rhui-1.1-5Server-x86_64 starting, skip_dict = {}
2011-05-16 12:32:00,550 [INFO][Thread-72] sync() @ repo_sync.py:447 - Limiting
download speed to 0 KB/sec per thread. [15] threads will be used
2011-05-16 12:32:06,631 [ERROR][Thread-72] failed() @ task.py:310 - Task
id:06910602-7f81-11e0-9b07-525400da69d0, method_name:_sync:
Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/pulp/server/tasking/task.py", line
258, in run
    result = self.callable(*self.args, **self.kwargs)
  File "/usr/lib/python2.6/site-packages/pulp/server/api/repo.py", line 1499,
in _sync
    threads)
  File "/usr/lib/python2.6/site-packages/pulp/server/api/repo_sync.py", line
146, in sync
    progress_callback, max_speed, threads)
  File "/usr/lib/python2.6/site-packages/pulp/server/api/repo_sync.py", line
460, in sync
    report = self.yum_repo_grinder.fetchYumRepo(store_path,
callback=progress_callback)
  File "/usr/lib/python2.6/site-packages/grinder/RepoFetch.py", line 366, in
fetchYumRepo
    self.prepareRPMS()
  File "/usr/lib/python2.6/site-packages/grinder/RepoFetch.py", line 244, in
prepareRPMS
    info['downloadurl'] = self.yumFetch.repourl + '/' + pkg.relativepath
  File "/usr/lib/python2.6/site-packages/yum/sqlitesack.py", line 268, in
__getattr__
    (self.pkgId,)).fetchone()
  File "/usr/lib/python2.6/site-packages/yum/sqlitesack.py", line 55, in
newFunc
    raise Errors.RepoError, str(e)
RepoError: SQLite objects created in a thread can only be used in that same
thread.The object was created in thread id 140370933417744 and this is thread
id 140370964887312

2011-05-16 12:32:06,631 [WARNING][Thread-72] schedule() @ task.py:192 - Task
06910602-7f81-11e0-9b07-525400da69d0: RepoApi._sync(rhui-1.1-5Server-x86_64,
synchronizer=<pulp.server.api.repo_sync.YumSynchronizer object at
0x7faac45d1ed0>) missed 1 scheduled runs
2011-05-16 12:32:17,287 [INFO][Thread-71] sync() @ repo_sync.py:463 -
YumSynchronizer reported 10 successes, 0 downloads, 0 errors
2011-05-16 12:32:18,027 [INFO][Thread-71] _process_repo_images() @
repo_sync.py:260 - No image files to import to repo..
2011-05-16 12:32:18,029 [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.1/os/repodata/comps-rhel5-server-rhui.xml
2011-05-16 12:32:18,029 [INFO][Thread-71] add_packages_from_dir() @
repo_sync.py:253 - Skipping errata imports from sync process
2011-05-16 12:32:18,030 [INFO][Thread-71] _sync() @ repo.py:1502 - Sync
returned 10 packages, 0 errata in 17.4895288944 seconds
2011-05-16 12:32:18,049 [INFO][Thread-71] _sync() @ repo.py:1513 - 6 old
packages to process, 6 new packages to process
2011-05-16 12:32:18,063 [INFO][Thread-71] create_repo() @ util.py:357 -
Checking what metadata types are available: ['filelists', 'other', 'group',
'primary', 'group_gz']
2011-05-16 12:32:18,620 [INFO][Thread-71] create_repo() @ util.py:369 -
[createrepo --checksum sha256 -g
/var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/i386/rhui/1.1/os/repodata/comps-rhel5-server-rhui.xml
--update
/var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/i386/rhui/1.1/os] on
/var/lib/pulp//repos/content/dist/rhel/rhui/server/5Server/i386/rhui/1.1/os
finished

Comment 1 Jay Dobies 2011-07-15 15:39:22 UTC
Closing as per the downstream bug resolution.


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