--- a/doc/book/en/annexes/rql/debugging.rst Fri Dec 14 14:08:14 2012 +0100
+++ b/doc/book/en/annexes/rql/debugging.rst Tue Dec 11 18:20:00 2012 +0100
@@ -15,6 +15,8 @@
.. autodata:: cubicweb.server.DBG_SQL
.. autodata:: cubicweb.server.DBG_REPO
.. autodata:: cubicweb.server.DBG_MS
+.. autodata:: cubicweb.server.DBG_HOOKS
+.. autodata:: cubicweb.server.DBG_OPS
.. autodata:: cubicweb.server.DBG_MORE
.. autodata:: cubicweb.server.DBG_ALL
@@ -31,6 +33,14 @@
.. autofunction:: cubicweb.server.set_debug
+Another example showing how to debug hooks at a specific code site:
+
+.. sourcecode:: python
+
+ from cubicweb.server import debuged, DBG_HOOKS
+ with debugged(DBG_HOOKS):
+ person.cw_set(works_for=company)
+
Detect largest RQL queries
~~~~~~~~~~~~~~~~~~~~~~~~~~~
--- a/server/__init__.py Fri Dec 14 14:08:14 2012 +0100
+++ b/server/__init__.py Tue Dec 11 18:20:00 2012 +0100
@@ -77,10 +77,14 @@
DBG_REPO = 4
#: multi-sources
DBG_MS = 8
+#: hooks
+DBG_HOOKS = 16
+#: operations
+DBG_OPS = 32
#: more verbosity
-DBG_MORE = 16
+DBG_MORE = 64
#: all level enabled
-DBG_ALL = DBG_RQL + DBG_SQL + DBG_REPO + DBG_MS + DBG_MORE
+DBG_ALL = DBG_RQL + DBG_SQL + DBG_REPO + DBG_MS + DBG_HOOKS + DBG_OPS + DBG_MORE
#: current debug mode
DEBUG = 0
--- a/server/hook.py Fri Dec 14 14:08:14 2012 +0100
+++ b/server/hook.py Tue Dec 11 18:20:00 2012 +0100
@@ -260,7 +260,7 @@
from logilab.common.registry import (Predicate, NotPredicate, OrPredicate,
classid, objectify_predicate, yes)
-from cubicweb import RegistryNotFound
+from cubicweb import RegistryNotFound, server
from cubicweb.cwvreg import CWRegistry, CWRegistryStore
from cubicweb.predicates import ExpectedValuePredicate, is_instance
from cubicweb.appobject import AppObject
@@ -325,8 +325,11 @@
for _kwargs in _iter_kwargs(entities, eids_from_to, kwargs):
hooks = sorted(self.filtered_possible_objects(pruned, session, **_kwargs),
key=lambda x: x.order)
+ debug = server.DEBUG & server.DBG_HOOKS
with session.security_enabled(write=False):
for hook in hooks:
+ if debug:
+ print event, _kwargs, hook
hook()
def get_pruned_hooks(self, session, event, entities, eids_from_to, kwargs):
--- a/server/session.py Fri Dec 14 14:08:14 2012 +0100
+++ b/server/session.py Tue Dec 11 18:20:00 2012 +0100
@@ -31,7 +31,7 @@
from logilab.common.textutils import unormalize
from logilab.common.registry import objectify_predicate
-from cubicweb import UnknownEid, QueryError, schema
+from cubicweb import UnknownEid, QueryError, schema, server
from cubicweb.req import RequestSessionBase
from cubicweb.dbapi import ConnectionProperties
from cubicweb.utils import make_uid
@@ -939,16 +939,21 @@
# information:
# - processed by the precommit/commit event or not
# - if processed, is it the failed operation
+ debug = server.DEBUG & server.DBG_OPS
try:
# by default, operations are executed with security turned off
with security_enabled(self, False, False):
processed = []
self.commit_state = 'precommit'
+ if debug:
+ print self.commit_state, '*' * 20
try:
while self.pending_operations:
operation = self.pending_operations.pop(0)
operation.processed = 'precommit'
processed.append(operation)
+ if debug:
+ print operation
operation.handle_event('precommit_event')
self.pending_operations[:] = processed
self.debug('precommit session %s done', self.id)
@@ -964,7 +969,11 @@
# instead of having to implements rollback, revertprecommit
# and revertcommit, that will be enough in mont case.
operation.failed = True
+ if debug:
+ print self.commit_state, '*' * 20
for operation in reversed(processed):
+ if debug:
+ print operation
try:
operation.handle_event('revertprecommit_event')
except BaseException:
@@ -977,8 +986,12 @@
raise
self.cnxset.commit()
self.commit_state = 'postcommit'
+ if debug:
+ print self.commit_state, '*' * 20
while self.pending_operations:
operation = self.pending_operations.pop(0)
+ if debug:
+ print operation
operation.processed = 'postcommit'
try:
operation.handle_event('postcommit_event')