# HG changeset patch # User Bernhard Reiter # Date 1357349481 -3600 # Node ID ae0af9a2a316b7c988d81cec063c6de1cd88bff6 # Parent 26a138760969ab1508d70ad75d4b48a39e1b9914 Better debugging. Using logger with backends/rdbms_common.py and test/detectors/tx_source_detector.py. diff -r 26a138760969 -r ae0af9a2a316 detectors/txSource_detector.py --- a/detectors/txSource_detector.py Wed Jan 02 22:26:31 2013 +0100 +++ /dev/null Thu Jan 01 00:00:00 1970 +0000 @@ -1,61 +0,0 @@ -# -# Example output when the web interface changes item 3 and the email -# (non pgp) interface changes item 4: -# -# txSourceCheckAudit(3) pre db.tx_Source: web -# txSourceCheckAudit(4) pre db.tx_Source: email -# txSourceCheckAudit(3) post db.tx_Source: web -# txSourceCheckAudit(4) post db.tx_Source: email -# txSourceCheckReact(4) pre db.tx_Source: email -# txSourceCheckReact(4) post db.tx_Source: email -# txSourceCheckReact(3) pre db.tx_Source: web -# txSourceCheckReact(3) post db.tx_Source: web -# -# Note that the calls are interleaved, but the proper -# txSource is associated with the same ticket. - -import time as time - -def txSourceCheckAudit(db, cl, nodeid, newvalues): - ''' An auditor to print the value of the source of the - transaction that trigger this change. The sleep call - is used to delay the transaction so that multiple changes will - overlap. The expected output from this detector are 2 lines - with the same value for txSource. Tx source is: - None - cli - reported when using a script/roundup-admin - web - reported when using any web based technique - email - reported when using any email based technique - email-sig-openpgp - reported when email based technique uses an openpgp signed emails - ''' - print "txSourceCheckAudit(%s) pre db.tx_Source: %s"%(nodeid, db.tx_Source) - time.sleep(10) - print "txSourceCheckAudit(%s) post db.tx_Source: %s"%(nodeid, db.tx_Source) - - # example use for real to prevent a change from happening if it's - # submited via email - # - # if db.tx_Source == "email": - # raise Reject, 'Change not allowed via email' - -def txSourceCheckReact(db, cl, nodeid, oldvalues): - ''' An reactor to print the value of the source of the - transaction that trigger this change. The sleep call - is used to delay the transaction so that multiple changes will - overlap. The expected output from this detector are 2 lines - with the same value for txSource. Tx source is: - None - cli - reported when using a script/roundup-admin - web - reported when using any web based technique - email - reported when using any email based technique - email-sig-openpgp - reported when email based technique uses pgp signed emails - ''' - print "txSourceCheckReact(%s) pre db.tx_Source: %s"%(nodeid, db.tx_Source) - time.sleep(10) - print "txSourceCheckReact(%s) post db.tx_Source: %s"%(nodeid, db.tx_Source) - -def init(db): - db.issue.audit('set', txSourceCheckAudit) - db.issue.audit('create', txSourceCheckAudit) - db.issue.react('set', txSourceCheckReact) - db.issue.react('create', txSourceCheckReact) diff -r 26a138760969 -r ae0af9a2a316 roundup/backends/rdbms_common.py --- a/roundup/backends/rdbms_common.py Wed Jan 02 22:26:31 2013 +0100 +++ b/roundup/backends/rdbms_common.py Sat Jan 05 02:31:21 2013 +0100 @@ -1720,6 +1720,8 @@ def set_inner(self, nodeid, **propvalues): """ Called by set, in-between the audit and react calls. """ + logger = logging.getLogger('roundup.hyperdb') + if not propvalues: return propvalues @@ -1739,6 +1741,8 @@ raise IndexError('Requested item is retired') num_re = re.compile('^\d+$') + logger.debug("set_inner node=%s"%(node)) + # make a copy of the values dictionary - we'll modify the contents propvalues = propvalues.copy() @@ -1750,6 +1754,7 @@ multilink_changes = {} for propname, value in list(propvalues.items()): + logger.debug("set_inner dealing with %s=%s"%(propname,value)) # check to make sure we're not duplicating an existing key if propname == self.key and node[propname] != value: try: @@ -1918,6 +1923,8 @@ except ValueError: raise TypeError('new property "%s" not boolean'%propname) + logger.debug("At the closing part of set_inner()") + # nothing to do? if not propvalues: return propvalues diff -r 26a138760969 -r ae0af9a2a316 share/roundup/templates/test/detectors/tx_source_detector.py --- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/share/roundup/templates/test/detectors/tx_source_detector.py Sat Jan 05 02:31:21 2013 +0100 @@ -0,0 +1,74 @@ +# +# Example output when the web interface changes item 3 and the email +# (non pgp) interface changes item 4: +# +# tx_SourceCheckAudit(3) pre db.tx_Source: web +# tx_SourceCheckAudit(4) pre db.tx_Source: email +# tx_SourceCheckAudit(3) post db.tx_Source: web +# tx_SourceCheckAudit(4) post db.tx_Source: email +# tx_SourceCheckReact(4) pre db.tx_Source: email +# tx_SourceCheckReact(4) post db.tx_Source: email +# tx_SourceCheckReact(3) pre db.tx_Source: web +# tx_SourceCheckReact(3) post db.tx_Source: web +# +# Note that the calls are interleaved, but the proper +# tx_Source is associated with the same ticket. + +import logging +import time as time +import os + +def tx_SourceCheckAudit(db, cl, nodeid, newvalues): + ''' An auditor to print the value of the source of the + transaction that trigger this change. The sleep call + is used to delay the transaction so that multiple changes will + overlap. The expected output from this detector are 2 lines + with the same value for tx_Source. Tx source is: + unset - reported when using a script/roundup-admin + cgi - reported when using any web based technique + email - reported when using any email based technique + email/pgp - reported when email based technique uses pgp signed emails + ''' + nonce = os.urandom(10).encode('hex') + logger = logging.getLogger('roundup') + + logger.info("tx_SourceCheckAudit(%s) pre db.tx_Source: %s, nonce: %s"%(nodeid, db.tx_Source, nonce)) + + time.sleep(10) + + newvalues['tx_Source'] = 'arrived via: %s %s' % (db.tx_Source, nonce) + + logger.info("tx_SourceCheckAudit(%s) post db.tx_Source: %s, nonce %s"%(nodeid, db.tx_Source, nonce)) + + # example use for real to prevent a change from happening if it's + # submited via email + # + # if db.tx_Source == "email": + # raise Reject, 'Change not allowed via email' + +def tx_SourceCheckReact(db, cl, nodeid, oldvalues): + ''' An reactor to print the value of the source of the + transaction that trigger this change. The sleep call + is used to delay the transaction so that multiple changes will + overlap. The expected output from this detector are 2 lines + with the same value for tx_Source. Tx source is: + unset - reported when using a script/roundup-admin + web - reported when using any web based technique + email - reported when using any email based technique + email/pgp - reported when email based technique uses pgp signed emails + ''' + + # get the tx_Source property using cl.get(nodeid, 'messages') + + logger = logging.getLogger('roundup') + logger.info("tx_SourceCheckReact(%s) pre db.tx_Source: %s, recorded: %s"%(nodeid, db.tx_Source, cl.get(nodeid, 'tx_Source'))) + time.sleep(10) + logger.info("tx_SourceCheckReact(%s) post db.tx_Source: %s, recorded: %s"%(nodeid, db.tx_Source, cl.get(nodeid, 'tx_Source'))) + +def init(db): + db.issue.audit('set', tx_SourceCheckAudit) + db.issue.audit('create', tx_SourceCheckAudit) + db.issue.react('set', tx_SourceCheckReact) + db.issue.react('create', tx_SourceCheckReact) + + db.msg.audit('create', tx_SourceCheckAudit)