[debug/rql] bind a uniq token per rql to trace its decomposition

This is aimed to be used by the RQL debug panel (and the SQL one later on) but
can also be used by other debugging tools.

cubicweb/server/querier.py

@@ -18,6 +18,7 @@
 """Helper classes to execute RQL queries on a set of sources, performing
 security checking and data aggregation.
 """
+import uuid
 from itertools import repeat
 
 from rql import RQLSyntaxError, CoercionError
@@ -164,6 +165,8 @@ class ExecutionPlan(object):
         self.querier = querier
         self.schema = querier.schema
         self.rqlhelper = cnx.vreg.rqlhelper
+        # tracing token for debugging
+        self.rql_query_tracing_token = None
 
     def annotate_rqlst(self):
         if not self.rqlst.annotated:
@@ -179,6 +182,7 @@ class ExecutionPlan(object):
     def execute(self):
         """execute a plan and return resulting rows"""
         for step in self.steps:
+            step.rql_query_tracing_token = self.rql_query_tracing_token
             result = step.execute()
         # the latest executed step contains the full query result
         return result
@@ -552,6 +556,7 @@ class QuerierHelper(object):
         # make an execution plan
         plan = self.plan_factory(rqlst, args, cnx)
         plan.cache_key = cachekey
+        plan.rql_query_tracing_token = str(uuid.uuid4())
         self._planner.build_plan(plan)
         # execute the plan
         try:

cubicweb/server/session.py

@@ -790,11 +790,12 @@ class Connection(RequestSessionBase):
         return service.call(**kwargs)
 
     @_open_only
-    def system_sql(self, sql, args=None, rollback_on_failure=True):
+    def system_sql(self, sql, args=None, rollback_on_failure=True, rql_query_tracing_token=None):
         """return a sql cursor on the system database"""
         source = self.repo.system_source
         try:
-            return source.doexec(self, sql, args, rollback=rollback_on_failure)
+            return source.doexec(self, sql, args, rollback=rollback_on_failure,
+                                 rql_query_tracing_token=rql_query_tracing_token)
         except (source.OperationalError, source.InterfaceError):
             if not rollback_on_failure:
                 raise

cubicweb/server/sources/native.py

@@ -499,7 +499,7 @@ class NativeSQLSource(SQLAdapterMixIn, AbstractSource):
                 continue
         raise AuthenticationError()
 
-    def syntax_tree_search(self, cnx, union, args=None, cachekey=None):
+    def syntax_tree_search(self, cnx, union, args=None, cachekey=None, rql_query_tracing_token=None):
         """return result from this source for a rql query (actually from
         a rql syntax tree and a solution dictionary mapping each used
         variable to a possible type). If cachekey is given, the query
@@ -523,7 +523,7 @@ class NativeSQLSource(SQLAdapterMixIn, AbstractSource):
                 self._cache[cachekey] = sql, qargs, cbs
         args = self.merge_args(args, qargs)
         assert isinstance(sql, str), repr(sql)
-        cursor = cnx.system_sql(sql, args)
+        cursor = cnx.system_sql(sql, args, rql_query_tracing_token=rql_query_tracing_token)
         results = self.process_result(cursor, cnx, cbs)
         assert dbg_results(results)
         return results
@@ -680,7 +680,7 @@ class NativeSQLSource(SQLAdapterMixIn, AbstractSource):
         self.doexec(cnx, sql, attrs)
 
     @statsd_timeit
-    def doexec(self, cnx, query, args=None, rollback=True):
+    def doexec(self, cnx, query, args=None, rollback=True, rql_query_tracing_token=None):
         """Execute a query.
         it's a function just so that it shows up in profiling
         """

cubicweb/server/ssplanner.py

@@ -344,6 +344,7 @@ class OneFetchStep(Step):
     def __init__(self, plan, union):
         Step.__init__(self, plan)
         self.union = union
+        self.rql_query_tracing_token = None
 
     def execute(self):
         """call .syntax_tree_search with the given syntax tree on each
@@ -365,7 +366,8 @@ class OneFetchStep(Step):
             cachekey = union.as_string()
         # get results for query
         source = cnx.repo.system_source
-        result = source.syntax_tree_search(cnx, union, args, cachekey)
+        result = source.syntax_tree_search(cnx, union, args, cachekey,
+                                           rql_query_tracing_token=self.rql_query_tracing_token)
         return result
 
     def mytest_repr(self):