Commit d0fa4610 authored by Nicolas Chauvat's avatar Nicolas Chauvat
Browse files

fix: do not consume a lot of time to collect debug data if no one is listening

--HG--
branch : 3.29
parent ad7e5b4d403d
......@@ -33,7 +33,7 @@ from rql import RQLHelper
from yams.constraints import BASE_CONVERTERS
from cubicweb import _
from cubicweb.debug import emit_to_debug_channel
from cubicweb.debug import debug_channel_has_subscribers, emit_to_debug_channel
from cubicweb import (CW_SOFTWARE_ROOT, ETYPE_NAME_MAP, CW_EVENT_MANAGER,
onevent, Binary, UnknownProperty, UnknownEid)
from cubicweb.predicates import appobject_selectable, _reset_is_instance_cache
......@@ -72,7 +72,8 @@ class CWRegistry(Registry):
"""
super(CWRegistry, self).__init__(True)
self.vreg = vreg
self.add_select_best_listener(self._emit_registry_debug_information)
if debug_channel_has_subscribers("registry_decisions"):
self.add_select_best_listener(self._emit_registry_debug_information)
def _emit_registry_debug_information(self, debug_registry_select_best):
emit_to_debug_channel("registry_decisions", debug_registry_select_best)
......
......@@ -30,6 +30,10 @@ SUBSCRIBERS = {
}
def debug_channel_has_subscribers(channel):
return len(SUBSCRIBERS.get(channel, [])) > 0
def subscribe_to_debug_channel(channel, subscriber):
"""
Allow to subscribe a callable to one of the debug channels.
......
......@@ -33,7 +33,7 @@ from cubicweb import ValidationError, Unauthorized, UnknownEid, QueryError
from cubicweb.rqlrewrite import RQLRelationRewriter
from cubicweb import Binary, server
from cubicweb.rset import ResultSet
from cubicweb.debug import emit_to_debug_channel
from cubicweb.debug import debug_channel_has_subscribers, emit_to_debug_channel
from cubicweb.utils import QueryCache, RepeatList
from cubicweb.misc.source_highlight import highlight_terminal
......@@ -511,6 +511,8 @@ class QuerierHelper(object):
always use substitute arguments in queries (i.e. avoid query such as
'Any X WHERE X eid 123'!)
"""
use_debug_channel = debug_channel_has_subscribers("rql")
if server.DEBUG & (server.DBG_RQL | server.DBG_SQL):
if server.DEBUG & (server.DBG_MORE | server.DBG_SQL):
print('*'*80)
......@@ -549,14 +551,15 @@ class QuerierHelper(object):
plan.rql_query_tracing_token = str(uuid.uuid4())
prepare_plan(plan, self.schema, self._repo.vreg.rqlhelper)
query_debug_informations = {
"rql": rql,
"rql_query_tracing_token": plan.rql_query_tracing_token,
"args": args,
# remove the last part of the stack which is: this line
"callstack": "".join(traceback.format_stack()[:-1]),
"description": "",
}
if use_debug_channel:
query_debug_informations = {
"rql": rql,
"rql_query_tracing_token": plan.rql_query_tracing_token,
"args": args,
# remove the last part of the stack which is: this line
"callstack": "".join(traceback.format_stack()[:-1]),
"description": "",
}
start = time.time()
# execute the plan
......@@ -575,8 +578,9 @@ class QuerierHelper(object):
cnx.commit_state = 'uncommitable'
raise
query_debug_informations["time"] = ((time.time() - start) * 1000)
query_debug_informations["result"] = results
if use_debug_channel:
query_debug_informations["time"] = (time.time() - start) * 1000
query_debug_informations["result"] = results
# build a description for the results if necessary
descr = ()
......@@ -604,9 +608,11 @@ class QuerierHelper(object):
descr = _build_descr(cnx, results, basedescr, todetermine)
# FIXME: get number of affected entities / relations on non
# selection queries ?
query_debug_informations["description"] = descr
if use_debug_channel:
query_debug_informations["description"] = descr
emit_to_debug_channel("rql", query_debug_informations)
if use_debug_channel:
emit_to_debug_channel("rql", query_debug_informations)
# return a result set object
return ResultSet(results, rql, args, descr, variables)
......
......@@ -41,7 +41,7 @@ from cubicweb import (UnknownEid, AuthenticationError, ValidationError, Binary,
UniqueTogetherError, UndoTransactionException, ViolatedConstraint)
from cubicweb import transaction as tx, server, neg_role, _
from cubicweb.utils import QueryCache
from cubicweb.debug import emit_to_debug_channel
from cubicweb.debug import debug_channel_has_subscribers, emit_to_debug_channel
from cubicweb.schema import VIRTUAL_RTYPES
from cubicweb.cwconfig import CubicWebNoAppConfiguration
from cubicweb.server import hook
......@@ -687,14 +687,15 @@ class NativeSQLSource(SQLAdapterMixIn, AbstractSource):
"""Execute a query.
it's a function just so that it shows up in profiling
"""
query_debug_informations = {
"sql": query,
"args": args,
"rollback": False,
"callstack": "".join(traceback.format_stack()[:-1]),
"rql_query_tracing_token": rql_query_tracing_token,
}
use_debug_channel = debug_channel_has_subscribers("sql")
if use_debug_channel:
query_debug_informations = {
"sql": query,
"args": args,
"rollback": False,
"callstack": "".join(traceback.format_stack()[:-1]),
"rql_query_tracing_token": rql_query_tracing_token,
}
start = time.time()
......@@ -713,7 +714,8 @@ class NativeSQLSource(SQLAdapterMixIn, AbstractSource):
if rollback:
try:
cnx.cnxset.rollback()
query_debug_informations["rollback"] = True
if use_debug_channel:
query_debug_informations["rollback"] = True
if self.repo.config.mode != 'test':
self.debug('transaction has been rolled back')
except Exception as rollback_exc:
......@@ -758,8 +760,9 @@ class NativeSQLSource(SQLAdapterMixIn, AbstractSource):
query=query)
raise
finally:
query_debug_informations["time"] = (time.time() - start) * 1000
emit_to_debug_channel("sql", query_debug_informations)
if use_debug_channel:
query_debug_informations["time"] = (time.time() - start) * 1000
emit_to_debug_channel("sql", query_debug_informations)
return cursor
@statsd_timeit
......
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