F: start to handle binary debug log level on the server side
authorSylvain Thénault <sylvain.thenault@logilab.fr>
Fri, 31 Jul 2009 23:25:02 +0200
changeset 2593 16d9419a4a79
parent 2592 c97c4b56e6a0
child 2594 92aad5e18405
F: start to handle binary debug log level on the server side
server/__init__.py
server/querier.py
server/sources/native.py
server/sources/pyrorql.py
--- a/server/__init__.py	Fri Jul 31 23:21:45 2009 +0200
+++ b/server/__init__.py	Fri Jul 31 23:25:02 2009 +0200
@@ -15,8 +15,40 @@
 
 from logilab.common.modutils import LazyObject
 
+# server-side debugging #########################################################
+
 # server debugging flag
-DEBUG = False
+DBG_RQL = 1 # rql execution information
+DBG_SQL = 2 # executed sql
+DBG_REPO = 4 # repository events
+DBG_MORE = 8 # repository events
+
+
+# 2: + executed sql
+# 3: + additional debug information
+DEBUG = 0
+def set_debug(debugmode):
+    global DEBUG
+    if not debugmode:
+        DEBUG = 0
+        return
+    if isinstance(debugmode, basestring):
+        debugmode = globals()[debugmode]
+    DEBUG |= debugmode
+
+def debugged(func):
+    """decorator to activate debug mode"""
+    def wrapped(*args, **kwargs):
+        global DEBUG
+        DEBUG = True
+        try:
+            return func(*args, **kwargs)
+        finally:
+            DEBUG = False
+    return wrapped
+
+
+# database initialization ######################################################
 
 def init_repository(config, interactive=True, drop=False, vreg=None):
     """initialise a repository database by creating tables add filling them
@@ -160,20 +192,6 @@
     for path in reversed(paths):
         mhandler.exec_event_script('post%s' % event, path)
 
-def set_debug(debugmode):
-    global DEBUG
-    DEBUG = debugmode
-
-def debugged(func):
-    """decorator to activate debug mode"""
-    def wrapped(*args, **kwargs):
-        global DEBUG
-        DEBUG = True
-        try:
-            return func(*args, **kwargs)
-        finally:
-            DEBUG = False
-    return wrapped
 
 # sqlite'stored procedures have to be registered at connexion opening time
 SQL_CONNECT_HOOKS = {}
--- a/server/querier.py	Fri Jul 31 23:21:45 2009 +0200
+++ b/server/querier.py	Fri Jul 31 23:25:02 2009 +0200
@@ -189,8 +189,6 @@
 
         return rqlst to actually execute
         """
-        #if server.DEBUG:
-        #    print '------- preprocessing', union.as_string('utf8')
         noinvariant = set()
         if security and not self.session.is_super_session:
             self._insert_security(union, noinvariant)
@@ -586,9 +584,9 @@
         always use substitute arguments in queries (eg avoid query such as
         'Any X WHERE X eid 123'!)
         """
-        if server.DEBUG:
+        if server.DEBUG & (server.DBG_RQL | server.DBG_RQL):
             print '*'*80
-            print rql
+            print 'QUERIER INPUT', rql
         # parse the query and binds variables
         if eid_key is not None:
             if not isinstance(eid_key, (tuple, list)):
--- a/server/sources/native.py	Fri Jul 31 23:21:45 2009 +0200
+++ b/server/sources/native.py	Fri Jul 31 23:25:02 2009 +0200
@@ -44,7 +44,7 @@
         """Execute a query.
         it's a function just so that it shows up in profiling
         """
-        if server.DEBUG:
+        if server.DEBUG & server.DBG_SQL:
             print 'exec', query, args
         try:
             self.cu.execute(str(query), args)
@@ -305,13 +305,15 @@
         necessary to fetch the results (but not the results themselves)
         may be cached using this key.
         """
-        if server.DEBUG:
-            print 'RQL FOR NATIVE SOURCE', self.uri, cachekey
+        if server.DEBUG & server.DBG_RQL:
+            print 'RQL FOR NATIVE SOURCE %s: %s' % (self.uri, union.as_string())
             if varmap:
-                print 'USING VARMAP', varmap
-            print union.as_string()
-            if args: print 'ARGS', args
-            print 'SOLUTIONS', ','.join(str(s.solutions) for s in union.children)
+                print 'using varmap', varmap
+            if args:
+                print 'args', args
+            if server.DEBUG & server.DBG_MORE:
+                print 'cache key', cachekey
+                print 'solutions', ','.join(str(s.solutions) for s in union.children)
         # remember number of actually selected term (sql generation may append some)
         if cachekey is None:
             self.no_cache += 1
@@ -337,7 +339,7 @@
             session.pool.reconnect(self)
             cursor = self.doexec(session, sql, args)
         res = self.process_result(cursor)
-        if server.DEBUG:
+        if server.DEBUG & (server.DBG_SQL | server.DBG_RQL):
             print '------>', res
         return res
 
@@ -348,12 +350,12 @@
         inserts all data by calling .executemany().
         """
         if self.uri == 'system':
-            if server.DEBUG:
-                print 'FLYING RQL FOR SOURCE', self.uri
+            if server.DEBUG & server.DBG_RQL:
+                print 'FLYING RQL FOR SOURCE %s: %s', self.uri, union.as_string()
                 if varmap:
                     print 'USING VARMAP', varmap
-                print union.as_string()
-                print 'SOLUTIONS', ','.join(str(s.solutions) for s in union.children)
+                if server.DEBUG & server.DBG_MORE:
+                    print 'SOLUTIONS', ','.join(str(s.solutions) for s in union.children)
             # generate sql queries if we are able to do so
             sql, query_args = self._rql_sqlgen.generate(union, args, varmap)
             query = 'INSERT INTO %s %s' % (table, sql.encode(self.encoding))
@@ -437,6 +439,8 @@
         if server.DEBUG:
             print 'exec', query, args
         cursor = session.pool[self.uri]
+        if server.DEBUG & server.DBG_SQL:
+            print 'exec', query, args, session.pool.connection(self.uri)._cnx
         try:
             # str(query) to avoid error if it's an unicode string
             cursor.execute(str(query), args)
@@ -455,7 +459,7 @@
         """Execute a query.
         it's a function just so that it shows up in profiling
         """
-        if server.DEBUG:
+        if server.DEBUG & server.DBG_SQL:
             print 'execmany', query, 'with', len(args), 'arguments'
         cursor = session.pool[self.uri]
         try:
--- a/server/sources/pyrorql.py	Fri Jul 31 23:21:45 2009 +0200
+++ b/server/sources/pyrorql.py	Fri Jul 31 23:25:02 2009 +0200
@@ -270,11 +270,12 @@
         """
         if not args is None:
             args = args.copy()
-        if server.DEBUG:
-            print 'RQL FOR PYRO SOURCE', self.uri
-            print union.as_string()
-            if args: print 'ARGS', args
-            print 'SOLUTIONS', ','.join(str(s.solutions) for s in union.children)
+        if server.DEBUG & server.DBG_RQL:
+            print 'RQL FOR PYRO SOURCE %s: %s', self.uri, union.as_string()
+            if args:
+                print 'ARGS', args
+            if server.DEBUG & server.DBG_MORE:
+                print 'SOLUTIONS', ','.join(str(s.solutions) for s in union.children)
         # get cached cursor anyway
         cu = session.pool[self.uri]
         if cu is None:
@@ -288,7 +289,7 @@
             if server.DEBUG:
                 print 'unknown eid', ex, 'no results'
             return []
-        if server.DEBUG:
+        if server.DEBUG & server.DBG_RQL:
             print 'TRANSLATED RQL', rql
         try:
             rset = cu.execute(rql, args, cachekey)
@@ -325,11 +326,11 @@
             results = rows
         else:
             results = []
-        if server.DEBUG:
+        if server.DEBUG & server.DBG_RQL:
             if len(results)>10:
-                print '--------------->', results[:10], '...', len(results)
+                print '-->', results[:10], '...', len(results)
             else:
-                print '--------------->', results
+                print '-->', results
         return results
 
     def _entity_relations_and_kwargs(self, session, entity):