After pulling a fresh copy of the production database to
'karlstaging', I'm seeing Gateway timeouts which may be related
to how RelStorage is using perfmetrics::
2013-03-27 12:28:32,608 - Thread -1256756416: Started on 1364401546.1; Running for 166.5 secs; request: GET https://karlstaging.gocept.com/communities/karl-developer-team/view.html
Traceback:
File "/srv/karlstaging/staging/29/eggs/slowlog-0.9-py2.6.egg/slowlog/tween.py", line 70, in __call__
return self.handler(request)
File "/srv/karlstaging/staging/29/eggs/pyramid-1.2.1-py2.6.egg/pyramid/tweens.py", line 17, in excview_tween
response = handler(request)
File "/srv/karlstaging/staging/29/eggs/pyramid_tm-0.5-py2.6.egg/pyramid_tm/__init__.py", line 100, in tm_tween
response = handler(request)
File "/srv/karlstaging/staging/29/eggs/pyramid-1.2.1-py2.6.egg/pyramid/router.py", line 153, in handle_request
response = view_callable(context, request)
File "/srv/karlstaging/staging/29/eggs/pyramid-1.2.1-py2.6.egg/pyramid/config/views.py", line 186, in _secured_view
return view(context, request)
File "/srv/karlstaging/staging/29/eggs/pyramid-1.2.1-py2.6.egg/pyramid/config/views.py", line 292, in rendered_view
result = view(context, request)
File "/srv/karlstaging/staging/29/src/karl/karl/views/community.py", line 136, in show_community_view
recent_items_batch = get_recent_items_batch(context, request)
File "/srv/karlstaging/staging/29/src/karl/karl/views/community.py", line 81, in get_recent_items_batch
allowed={'query': effective_principals(request), 'operator': 'or'},
File "/srv/karlstaging/staging/29/src/karl/karl/views/batch.py", line 144, in get_catalog_batch_grid
batch = get_catalog_batch(context, request, **kw)
File "/srv/karlstaging/staging/29/src/karl/karl/views/batch.py", line 51, in get_catalog_batch
total, docids, resolver = searcher(**kw)
File "/srv/karlstaging/staging/29/src/karl/karl/models/adapters.py", line 77, in __call__
num, docids = self.catalog.search(**kw)
File "/srv/karlstaging/staging/29/eggs/perfmetrics-1.0-py2.6.egg/perfmetrics/__init__.py", line 138, in call_with_metric
return f(*args, **kw)
File "/srv/karlstaging/staging/29/src/karl/karl/models/catalog.py", line 99, in search
num, docids = self._search(*arg, **kw)
File "/srv/karlstaging/staging/29/eggs/perfmetrics-1.0-py2.6.egg/perfmetrics/__init__.py", line 138, in call_with_metric
return f(*args, **kw)
File "/srv/karlstaging/staging/29/src/karl/karl/models/catalog.py", line 120, in _search
res = super(CachingCatalog, self).search(*arg, **kw)
File "/srv/karlstaging/staging/29/eggs/repoze.catalog-0.7.3-py2.6.egg/repoze/catalog/catalog.py", line 84, in search
r = index.apply(index_query)
File "/srv/karlstaging/staging/29/eggs/repoze.catalog-0.7.3-py2.6.egg/repoze/catalog/indexes/path2.py", line 357, in apply
return self.search(path, depth, include_path, attr_checker)
File "/srv/karlstaging/staging/29/eggs/repoze.catalog-0.7.3-py2.6.egg/repoze/catalog/indexes/path2.py", line 218, in search
return self._simple_search(path, depth, include_path)
File "/srv/karlstaging/staging/29/eggs/repoze.catalog-0.7.3-py2.6.egg/repoze/catalog/indexes/path2.py", line 247, in _simple_search
theset = self.adjacency[docid]
File "/srv/karlstaging/staging/29/eggs/ZODB3-3.10.5_perfmetrics-py2.6-linux-i686.egg/ZODB/Connection.py", line 860, in setstate
self._setstate(obj)
File "/srv/karlstaging/staging/29/eggs/ZODB3-3.10.5_perfmetrics-py2.6-linux-i686.egg/ZODB/Connection.py", line 901, in _setstate
p, serial = self._storage.load(obj._p_oid, '')
File "/srv/karlstaging/staging/29/eggs/perfmetrics-1.0-py2.6.egg/perfmetrics/__init__.py", line 114, in call_with_metric
return f(*args, **kw)
File "/srv/karlstaging/staging/29/eggs/RelStorage-1.5.1_perfmetrics2-py2.6.egg/relstorage/storage.py", line 460, in load
state, tid_int = cache.load(cursor, oid_int)
File "/srv/karlstaging/staging/29/eggs/RelStorage-1.5.1_perfmetrics2-py2.6.egg/relstorage/cache.py", line 279, in load
state, tid_int = self.adapter.mover.load_current(cursor, oid_int)
File "/srv/karlstaging/staging/29/eggs/perfmetrics-1.0-py2.6.egg/perfmetrics/__init__.py", line 114, in call_with_metric
return f(*args, **kw)
File "/srv/karlstaging/staging/29/eggs/RelStorage-1.5.1_perfmetrics2-py2.6.egg/relstorage/adapters/mover.py", line 104, in postgresql_load_current
cursor.execute(stmt, (oid,))
It looks as though there are changes on the 'RelStorage' trunk
which mitigate this issue via sampling:
https://github.com/zodb/relstorage/commit/d720f779dc02aef074b90f54e3d92088817aa899
I'm going to ask Shane if he can make a new release for us to
test on 'karlstaging'.
Replaced by a ticket that is a little more accurate.