Commit 4938ef3f authored by Hanno Schlichting's avatar Hanno Schlichting

Actually expose the query plan TTW

parent bb5b83eb
...@@ -48,6 +48,7 @@ from Products.ZCatalog.Catalog import Catalog, CatalogError ...@@ -48,6 +48,7 @@ from Products.ZCatalog.Catalog import Catalog, CatalogError
from Products.ZCatalog.interfaces import IZCatalog from Products.ZCatalog.interfaces import IZCatalog
from Products.ZCatalog.ProgressHandler import ZLogHandler from Products.ZCatalog.ProgressHandler import ZLogHandler
from Products.ZCatalog.ZCatalogIndexes import ZCatalogIndexes from Products.ZCatalog.ZCatalogIndexes import ZCatalogIndexes
from .plan import PriorityMap
LOG = logging.getLogger('Zope.ZCatalog') LOG = logging.getLogger('Zope.ZCatalog')
...@@ -103,7 +104,8 @@ class ZCatalog(Folder, Persistent, Implicit): ...@@ -103,7 +104,8 @@ class ZCatalog(Folder, Persistent, Implicit):
{'label': 'Metadata', 'action': 'manage_catalogSchema'}, {'label': 'Metadata', 'action': 'manage_catalogSchema'},
{'label': 'Find Objects', 'action': 'manage_catalogFind'}, {'label': 'Find Objects', 'action': 'manage_catalogFind'},
{'label': 'Advanced', 'action': 'manage_catalogAdvanced'}, {'label': 'Advanced', 'action': 'manage_catalogAdvanced'},
{'label': 'Query Report', 'action': 'manage_catalogPlan'}, {'label': 'Query Report', 'action': 'manage_catalogReport'},
{'label': 'Query Plan', 'action': 'manage_catalogPlan'},
{'label': 'Undo', 'action': 'manage_UndoForm'}, {'label': 'Undo', 'action': 'manage_UndoForm'},
{'label': 'Security', 'action': 'manage_access'}, {'label': 'Security', 'action': 'manage_access'},
{'label': 'Ownership', 'action': 'manage_owner'}, {'label': 'Ownership', 'action': 'manage_owner'},
...@@ -127,6 +129,9 @@ class ZCatalog(Folder, Persistent, Implicit): ...@@ -127,6 +129,9 @@ class ZCatalog(Folder, Persistent, Implicit):
'manage_catalogAdvanced') 'manage_catalogAdvanced')
manage_catalogAdvanced = DTMLFile('dtml/catalogAdvanced', globals()) manage_catalogAdvanced = DTMLFile('dtml/catalogAdvanced', globals())
security.declareProtected(manage_zcatalog_entries, 'manage_catalogReport')
manage_catalogReport = DTMLFile('dtml/catalogReport', globals())
security.declareProtected(manage_zcatalog_entries, 'manage_catalogPlan') security.declareProtected(manage_zcatalog_entries, 'manage_catalogPlan')
manage_catalogPlan = DTMLFile('dtml/catalogPlan', globals()) manage_catalogPlan = DTMLFile('dtml/catalogPlan', globals())
...@@ -877,24 +882,39 @@ class ZCatalog(Folder, Persistent, Implicit): ...@@ -877,24 +882,39 @@ class ZCatalog(Folder, Persistent, Implicit):
security.declareProtected(manage_zcatalog_entries, 'getCatalogPlan') security.declareProtected(manage_zcatalog_entries, 'getCatalogPlan')
def getCatalogPlan(self): def getCatalogPlan(self):
"""Query time reporting and planning.""" """Get a string representation of a query plan"""
plan = PriorityMap.get_plan()
output = []
output.append('queryplan = {')
for querykey, details in sorted(plan.items()):
output.append(' %s: {' % repr(querykey))
for indexname, benchmark in sorted(details.items()):
tuplebench = repr(tuple(benchmark))
output.append(' %r:\n %s,' % (indexname, tuplebench))
output.append(' },')
output.append('}')
return '\n'.join(output)
security.declareProtected(manage_zcatalog_entries, 'getCatalogReport')
def getCatalogReport(self):
"""Query time reporting."""
rval = self._catalog.getCatalogPlan().report() rval = self._catalog.getCatalogPlan().report()
rval.sort(key=operator.itemgetter('duration'), reverse=True) rval.sort(key=operator.itemgetter('duration'), reverse=True)
return rval return rval
security.declareProtected(manage_zcatalog_entries, security.declareProtected(manage_zcatalog_entries,
'manage_resetCatalogPlan') 'manage_resetCatalogReport')
def manage_resetCatalogPlan(self, REQUEST=None): def manage_resetCatalogReport(self, REQUEST=None):
"""Resets the catalog plan.""" """Resets the catalog report."""
self._catalog.getCatalogPlan().reset() self._catalog.getCatalogPlan().reset()
if REQUEST is not None: if REQUEST is not None:
REQUEST.response.redirect(REQUEST.URL1 + REQUEST.response.redirect(REQUEST.URL1 +
'/manage_catalogPlan?manage_tabs_message=Plan%20cleared') '/manage_catalogReport?manage_tabs_message=Report%20cleared')
security.declareProtected(manage_zcatalog_entries, security.declareProtected(manage_zcatalog_entries,
'manage_editCatalogPlan') 'manage_editCatalogReport')
def manage_editCatalogPlan(self, long_query_time=0.1, REQUEST=None): def manage_editCatalogReport(self, long_query_time=0.1, REQUEST=None):
"""Edit the long query time.""" """Edit the long query time."""
if not isinstance(long_query_time, float): if not isinstance(long_query_time, float):
long_query_time = float(long_query_time) long_query_time = float(long_query_time)
...@@ -902,7 +922,7 @@ class ZCatalog(Folder, Persistent, Implicit): ...@@ -902,7 +922,7 @@ class ZCatalog(Folder, Persistent, Implicit):
if REQUEST is not None: if REQUEST is not None:
REQUEST.response.redirect(REQUEST.URL1 + REQUEST.response.redirect(REQUEST.URL1 +
'/manage_catalogPlan?manage_tabs_message=' + '/manage_catalogReport?manage_tabs_message=' +
'Long%20query%20time%20changed') 'Long%20query%20time%20changed')
InitializeClass(ZCatalog) InitializeClass(ZCatalog)
......
...@@ -17,6 +17,10 @@ import ZCatalog ...@@ -17,6 +17,10 @@ import ZCatalog
def initialize(context): def initialize(context):
# Load a default map
from Products.ZCatalog.plan import PriorityMap
PriorityMap.load_default()
context.registerClass( context.registerClass(
ZCatalog.ZCatalog, ZCatalog.ZCatalog,
permission='Add ZCatalogs', permission='Add ZCatalogs',
......
...@@ -2,117 +2,12 @@ ...@@ -2,117 +2,12 @@
<dtml-var manage_tabs> <dtml-var manage_tabs>
<p class="form-help"> <p class="form-help">
The <strong>query report</strong> shows catalog queries that The <strong>query plan</strong> shows the actual query plan of the
perform slowly. current process.
</p> </p>
<table width="100%" cellspacing="0" cellpadding="2" border="0"> <textarea name="queryplan" cols="70" rows="25" readonly="readonly">
<tr class="list-header" > &dtml-getCatalogPlan;
<td align="left" valign="top"> </textarea>
<div class="list-nav">
Mean duration&nbsp;[ms]
</div>
</td>
<td align="left" valign="top">
<div class="list-nav">
Hits
</div>
</td>
<td align="left" valign="top">
<div class="list-nav">
Query key
</div>
</td>
<td align="left" valign="top">
<div class="list-nav">
Recent
</div>
</td>
</tr>
<dtml-if getCatalogPlan>
<dtml-in getCatalogPlan mapping>
<dtml-if sequence-odd>
<tr class="row-normal">
<dtml-else>
<tr class="row-hilite">
</dtml-if>
<td align="left" valign="top">
<div class="list-item">
<dtml-var expr="'%3.2f' % duration">
</div>
</td>
<td align="left" valign="top">
<div class="list-item">
&dtml-counter;
</div>
</td>
<td align="left" valign="top">
<div class="list-item">
&dtml-query;
</div>
</td>
<td align="left" valign="top">
<div class="list-item">
<dtml-var expr="'%3.2f' % last['duration']">ms
[<dtml-in expr="last['details']" sort mapping>
&dtml-id;:
<dtml-var expr="'%3.2f' % duration">ms /
&dtml-length; objects,
</dtml-in>]
</div>
</td>
</tr>
</dtml-in>
<tr>
<td colspan="2" align="left" valign="top">
<p class="form-help">Resetting the catalog report will reinitialize the report log.</p>
</td>
<td colspan="2" align="right" valign="top">
<form action="manage_resetCatalogPlan" method=POST>
<div class="form-element">
<input class="form-element" type="submit" value="Reset Report">
</div>
</form>
</td>
</tr>
<dtml-else>
<tr>
<td colspan="4" >
<div class="list-item">
Report is empty.
</div>
</td>
</tr>
</dtml-if>
</table>
<form action="manage_editCatalogPlan" method="post">
<table width="100%" style="padding-top:1em;" cellspacing="0" cellpadding="2" border="0">
<tr class="section-bar">
<td colspan="3" align="left">
<div class="form-label">
Settings
</div>
</td>
</tr>
<tr>
<td align="right" valign="middle">
<div class="list-item">
Threshold (in seconds)
</div>
</td>
<td align="left" valign="middle">
<div class="form-element">
<input name="long_query_time:float" value="&dtml-long_query_time;" />
</div>
</td>
<td align="left" valign="middle">
<p class="form-help">Only queries whose execution
takes longer than the configured threshold are considered
being slow. (Default 0.1 seconds).</p>
</tr>
</table>
<input class="form-element" type="submit" value="Apply settings">
</form>
<dtml-var manage_page_footer> <dtml-var manage_page_footer>
<dtml-var manage_page_header>
<dtml-var manage_tabs>
<p class="form-help">
The <strong>query report</strong> shows catalog queries that
perform slowly.
</p>
<table width="100%" cellspacing="0" cellpadding="2" border="0">
<tr class="list-header" >
<td align="left" valign="top">
<div class="list-nav">
Mean duration&nbsp;[ms]
</div>
</td>
<td align="left" valign="top">
<div class="list-nav">
Hits
</div>
</td>
<td align="left" valign="top">
<div class="list-nav">
Query key
</div>
</td>
<td align="left" valign="top">
<div class="list-nav">
Recent
</div>
</td>
</tr>
<dtml-if getCatalogReport>
<dtml-in getCatalogReport mapping>
<dtml-if sequence-odd>
<tr class="row-normal">
<dtml-else>
<tr class="row-hilite">
</dtml-if>
<td align="left" valign="top">
<div class="list-item">
<dtml-var expr="'%3.2f' % duration">
</div>
</td>
<td align="left" valign="top">
<div class="list-item">
&dtml-counter;
</div>
</td>
<td align="left" valign="top">
<div class="list-item">
&dtml-query;
</div>
</td>
<td align="left" valign="top">
<div class="list-item">
<dtml-var expr="'%3.2f' % last['duration']">ms
[<dtml-in expr="last['details']" sort mapping>
&dtml-id;:
<dtml-var expr="'%3.2f' % duration">ms /
&dtml-length; objects,
</dtml-in>]
</div>
</td>
</tr>
</dtml-in>
<tr>
<td colspan="2" align="left" valign="top">
<p class="form-help">Resetting the catalog report will reinitialize the report log.</p>
</td>
<td colspan="2" align="right" valign="top">
<form action="manage_resetCatalogReport" method=POST>
<div class="form-element">
<input class="form-element" type="submit" value="Reset Report">
</div>
</form>
</td>
</tr>
<dtml-else>
<tr>
<td colspan="4" >
<div class="list-item">
Report is empty.
</div>
</td>
</tr>
</dtml-if>
</table>
<form action="manage_editCatalogReport" method="post">
<table width="100%" style="padding-top:1em;" cellspacing="0" cellpadding="2" border="0">
<tr class="section-bar">
<td colspan="3" align="left">
<div class="form-label">
Settings
</div>
</td>
</tr>
<tr>
<td align="right" valign="middle">
<div class="list-item">
Threshold (in seconds)
</div>
</td>
<td align="left" valign="middle">
<div class="form-element">
<input name="long_query_time:float" value="&dtml-long_query_time;" />
</div>
</td>
<td align="left" valign="middle">
<p class="form-help">Only queries whose execution
takes longer than the configured threshold are considered
being slow. (Default 0.1 seconds).</p>
</tr>
</table>
<input class="form-element" type="submit" value="Apply settings">
</form>
<dtml-var manage_page_footer>
...@@ -41,6 +41,10 @@ class PriorityMap(object): ...@@ -41,6 +41,10 @@ class PriorityMap(object):
lock = allocate_lock() lock = allocate_lock()
value = {} value = {}
@classmethod
def get_plan(cls):
return cls.value.copy()
@classmethod @classmethod
def get(cls, key): def get(cls, key):
return cls.value.get(key, None) return cls.value.get(key, None)
...@@ -63,14 +67,17 @@ class PriorityMap(object): ...@@ -63,14 +67,17 @@ class PriorityMap(object):
pmap = resolve(location) pmap = resolve(location)
logger.info('loaded priority %d map(s) from %s', logger.info('loaded priority %d map(s) from %s',
len(pmap), location) len(pmap), location)
# Convert simple benchmark tuples to namedtuples
new_plan = {}
for querykey, details in pmap.items():
new_plan[querykey] = {}
for indexname, benchmark in details.items():
new_plan[querykey][indexname] = Benchmark(*benchmark)
with cls.lock: with cls.lock:
cls.value = pmap.copy() cls.value = new_plan
except ImportError: except ImportError:
logger.warning('could not load priority map from %s', location) logger.warning('could not load priority map from %s', location)
# Load a default map
PriorityMap.load_default()
class Reports(object): class Reports(object):
"""This holds a structure of nested dicts. """This holds a structure of nested dicts.
......
...@@ -46,7 +46,7 @@ class TestCatalogPlan(unittest.TestCase): ...@@ -46,7 +46,7 @@ class TestCatalogPlan(unittest.TestCase):
def test_ReportLength(self): def test_ReportLength(self):
""" tests the report aggregation """ """ tests the report aggregation """
self.zcat.manage_resetCatalogPlan() self.zcat.manage_resetCatalogReport()
self.zcat.searchResults(numbers=4, sort_on='num') self.zcat.searchResults(numbers=4, sort_on='num')
self.zcat.searchResults(numbers=1, sort_on='num') self.zcat.searchResults(numbers=1, sort_on='num')
...@@ -58,49 +58,49 @@ class TestCatalogPlan(unittest.TestCase): ...@@ -58,49 +58,49 @@ class TestCatalogPlan(unittest.TestCase):
self.zcat.searchResults(num=[5, 4, 3], sort_on='num') self.zcat.searchResults(num=[5, 4, 3], sort_on='num')
self.zcat.searchResults(num=(3, 4, 5), sort_on='num') self.zcat.searchResults(num=(3, 4, 5), sort_on='num')
self.assertEqual(4, len(self.zcat.getCatalogPlan())) self.assertEqual(4, len(self.zcat.getCatalogReport()))
def test_ReportCounter(self): def test_ReportCounter(self):
""" tests the counter of equal queries """ """ tests the counter of equal queries """
self.zcat.manage_resetCatalogPlan() self.zcat.manage_resetCatalogReport()
self.zcat.searchResults(numbers=5, sort_on='num') self.zcat.searchResults(numbers=5, sort_on='num')
self.zcat.searchResults(numbers=6, sort_on='num') self.zcat.searchResults(numbers=6, sort_on='num')
self.zcat.searchResults(numbers=8, sort_on='num') self.zcat.searchResults(numbers=8, sort_on='num')
r = self.zcat.getCatalogPlan()[0] r = self.zcat.getCatalogReport()[0]
self.assertEqual(r['counter'], 3) self.assertEqual(r['counter'], 3)
def test_ReportKey(self): def test_ReportKey(self):
""" tests the query keys for uniqueness """ """ tests the query keys for uniqueness """
# query key 1 # query key 1
key = ('sort_on', ('big', 'True')) key = ('sort_on', ('big', 'True'))
self.zcat.manage_resetCatalogPlan() self.zcat.manage_resetCatalogReport()
self.zcat.searchResults(big=True, sort_on='num') self.zcat.searchResults(big=True, sort_on='num')
self.zcat.searchResults(big=True, sort_on='num') self.zcat.searchResults(big=True, sort_on='num')
r = self.zcat.getCatalogPlan()[0] r = self.zcat.getCatalogReport()[0]
self.assertEqual(r['query'], key) self.assertEqual(r['query'], key)
self.assertEqual(r['counter'], 2) self.assertEqual(r['counter'], 2)
# query key 2 # query key 2
key = ('sort_on', ('big', 'False')) key = ('sort_on', ('big', 'False'))
self.zcat.manage_resetCatalogPlan() self.zcat.manage_resetCatalogReport()
self.zcat.searchResults(big=False, sort_on='num') self.zcat.searchResults(big=False, sort_on='num')
r = self.zcat.getCatalogPlan()[0] r = self.zcat.getCatalogReport()[0]
self.assertEqual(r['query'], key) self.assertEqual(r['query'], key)
self.assertEqual(r['counter'], 1) self.assertEqual(r['counter'], 1)
# query key 3 # query key 3
key = ('sort_on', ('num', '[3, 4, 5]')) key = ('sort_on', ('num', '[3, 4, 5]'))
self.zcat.manage_resetCatalogPlan() self.zcat.manage_resetCatalogReport()
self.zcat.searchResults(num=[5, 4, 3], sort_on='num') self.zcat.searchResults(num=[5, 4, 3], sort_on='num')
self.zcat.searchResults(num=(3, 4, 5), sort_on='num') self.zcat.searchResults(num=(3, 4, 5), sort_on='num')
r = self.zcat.getCatalogPlan()[0] r = self.zcat.getCatalogReport()[0]
self.assertEqual(r['query'], key) self.assertEqual(r['query'], key)
self.assertEqual(r['counter'], 2) self.assertEqual(r['counter'], 2)
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment