# HG changeset patch # User Sandrine Ribeau # Date 1231261835 28800 # Node ID abb7ea9bed71c08f698650b9d5388471a1578ae5 # Parent 643db91242b11a267112d5144335ea69d63a194b# Parent c65eccf85895d81f91e5d639ff7f86c48115c12c merge diff -r 643db91242b1 -r abb7ea9bed71 __init__.py --- a/__init__.py Mon Jan 05 10:40:22 2009 -0800 +++ b/__init__.py Tue Jan 06 09:10:35 2009 -0800 @@ -23,33 +23,11 @@ from logilab.common.decorators import cached - -LLDEBUG = 5 -logging.addLevelName(LLDEBUG, 'LLDEBUG') - -class CubicWebLogger(logging.Logger): - - def lldebug(self, msg, *args, **kwargs): - """ - Log 'msg % args' with severity 'DEBUG'. - - To pass exception information, use the keyword argument exc_info with - a true value, e.g. - - logger.debug("Houston, we have a %s", "thorny problem", exc_info=1) - """ - if self.manager.disable >= LLDEBUG: - return - if LLDEBUG >= self.getEffectiveLevel(): - self._log(LLDEBUG, msg, args, **kwargs) - -logging.setLoggerClass(CubicWebLogger) - def set_log_methods(cls, logger): """bind standart logger's methods as static methods on the class """ cls._logger = logger - for attr in ('lldebug', 'debug', 'info', 'warning', 'error', 'critical', 'exception'): + for attr in ('debug', 'info', 'warning', 'error', 'critical', 'exception'): setattr(cls, attr, getattr(logger, attr)) if os.environ.get('APYCOT_ROOT'): diff -r 643db91242b1 -r abb7ea9bed71 common/selectors.py --- a/common/selectors.py Mon Jan 05 10:40:22 2009 -0800 +++ b/common/selectors.py Tue Jan 06 09:10:35 2009 -0800 @@ -3,6 +3,35 @@ A selector is responsible to score how well an object may be used with a given result set (publishing time selection) +If you have trouble with selectors, especially if the objet (typically +a view or a component) you want to use is not selected and you want to +know which one(s) of its selectors fail (e.g. returns 0), you can use +`traced_selection` or even direclty `TRACED_OIDS`. + +`TRACED_OIDS` is a tuple of traced object ids. The special value +'all' may be used to log selectors for all objects. + +For instance, say that the following code yields a `NoSelectableObject` +exception:: + + self.view('calendar', myrset) + +You can log the selectors involved for *calendar* by replacing the line +above by:: + + # in Python2.5 + from cubicweb.selectors import traced_selection + with traced_selection(): + self.view('calendar', myrset) + + # in Python2.4 + from cubicweb import selectors + selectors.TRACED_OIDS = ('calendar',) + self.view('calendar', myrset) + selectors.TRACED_OIDS = () + + + :organization: Logilab :copyright: 2001-2008 LOGILAB S.A. (Paris, FRANCE), all rights reserved. :contact: http://www.logilab.fr/ -- mailto:contact@logilab.fr @@ -10,6 +39,8 @@ __docformat__ = "restructuredtext en" +import logging + from logilab.common.compat import all from logilab.common.deprecation import deprecated_function @@ -20,16 +51,49 @@ from cubicweb.schema import split_expression +# helpers for debugging selectors +SELECTOR_LOGGER = logging.getLogger('cubicweb.selectors') +TRACED_OIDS = () + def lltrace(selector): # don't wrap selectors if not in development mode if CubicWebConfiguration.mode == 'installed': return selector def traced(cls, *args, **kwargs): ret = selector(cls, *args, **kwargs) - cls.lldebug('selector %s returned %s for %s', selector.__name__, ret, cls) + if TRACED_OIDS == 'all' or cls.id in TRACED_OIDS: + SELECTOR_LOGGER.warning('selector %s returned %s for %s', selector.__name__, ret, cls) return ret return traced + +class traced_selection(object): + """selector debugging helper. + + Typical usage is : + + >>> with traced_selection(): + ... # some code in which you want to debug selectors + ... # for all objects + + or + + >>> with traced_selection( ('oid1', 'oid2') ): + ... # some code in which you want to debug selectors + ... # for objects with id 'oid1' and 'oid2' + """ + def __init__(self, traced='all'): + self.traced = traced + + def __enter__(self): + global TRACED_OIDS + TRACED_OIDS = self.traced + + def __exit__(self, exctype, exc, traceback): + global TRACED_OIDS + TRACED_OIDS = () + return traceback is None + # very basic selectors ######################################################## def yes(cls, *args, **kwargs): diff -r 643db91242b1 -r abb7ea9bed71 devtools/exlog.py --- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/devtools/exlog.py Tue Jan 06 09:10:35 2009 -0800 @@ -0,0 +1,39 @@ +""" +usage: python exlog.py < rql.log + +will print out the following table + + total execution time || number of occurences || rql query + +sorted by descending total execution time + +chances are the lines at the top are the ones that will bring +the higher benefit after optimisation. Start there. +""" +import sys, re + +def run(): + requests = {} + for line in sys.stdin: + if not ' WHERE ' in line: + continue + #sys.stderr.write( line ) + rql, time = line.split('--') + rql = re.sub("(\'\w+': \d*)", '', rql) + req = requests.setdefault(rql, []) + time.strip() + chunks = time.split() + cputime = float(chunks[-3]) + req.append( cputime ) + + stat = [] + for rql, times in requests.items(): + stat.append( (sum(times), len(times), rql) ) + + stat.sort() + stat.reverse() + for time, occ, rql in stat: + print time, occ, rql + +if __name__ == '__main__': + run() diff -r 643db91242b1 -r abb7ea9bed71 web/component.py --- a/web/component.py Mon Jan 05 10:40:22 2009 -0800 +++ b/web/component.py Tue Jan 06 09:10:35 2009 -0800 @@ -10,10 +10,10 @@ from cubicweb.common.utils import merge_dicts from cubicweb.common.view import VComponent, SingletonVComponent from cubicweb.common.registerers import action_registerer -from cubicweb.common.selectors import (paginated_rset, one_line_rset, - etype_rtype_selector, rqlcondition_selector, - accept_selector, contextprop_selector, - primaryview_selector, accept_rtype_selector) +from cubicweb.common.selectors import (paginated_rset, one_line_rset, + rql_condition, accept, primary_view, + match_context_prop, has_relation, + etype_rtype_selector) from cubicweb.common.uilib import html_escape _ = unicode @@ -32,10 +32,10 @@ __registry__ = 'contentnavigation' __registerer__ = action_registerer - __selectors__ = (one_line_rset, primaryview_selector, - contextprop_selector, etype_rtype_selector, - accept_rtype_selector, accept_selector, - rqlcondition_selector) + __selectors__ = (one_line_rset, primary_view, + match_context_prop, etype_rtype_selector, + has_relation, accept, + rql_condition) property_defs = { _('visible'): dict(type='Boolean', default=True, @@ -135,9 +135,9 @@ class RelatedObjectsVComponent(EntityVComponent): """a section to display some related entities""" - __selectors__ = (one_line_rset, primaryview_selector, - etype_rtype_selector, accept_rtype_selector, - contextprop_selector, accept_selector) + __selectors__ = (one_line_rset, primary_view, + etype_rtype_selector, has_relation, + match_context_prop, accept) vid = 'list' def rql(self):