merge
authorSandrine Ribeau <sandrine.ribeau@logilab.fr>
Tue, 06 Jan 2009 09:10:35 -0800
changeset 336 abb7ea9bed71
parent 335 643db91242b1 (current diff)
parent 333 c65eccf85895 (diff)
child 337 eb329d0db467
merge
--- 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'):
--- 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):
--- /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()
--- 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):