<br><div class="gmail_quote">On Thu, Jun 28, 2012 at 9:40 PM, Dan Stromberg <span dir="ltr"><<a href="mailto:drsalists@gmail.com" target="_blank">drsalists@gmail.com</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
<div style="margin-left:40px"><br></div>Hi.<br><br>I'm a Twisted neophyte, but I've been using Python a long time.<br><br>My question:<br>
<div style="margin-left:40px">Is there a way of producing a deferred
graph in a Python program at a given point in time? Perhaps something
based on graphviz and objgraph.py? We're able to detect when we're
having the problem, we just don't (yet) know its cause.<br>
</div>
<br><br>Background:<br><div style="margin-left:40px">I'm looking at some code with a bit over 200 addCallback/addErrback/addCallbacks in it.<br><br>It's got a problem where sometimes the deferreds seem to just stop executing. I see in the doc it says that this can happen if you've neglected to add an errback to the end of one or more of your deferred chains.<br>
<br>One of the people who's been here longer than me, indicated that he's gone through the code looking for such issues, and didn't find any. This suggests to me that either there's some other cause, or that it really is a deferred without a final errback, but it's hidden in a dark corner of the code somewhere.<br>
</div><br><br>Thanks!<br><br>
</blockquote></div>I put together something to do a single-point-in-time graph (as distorted/delayed by the time it takes to go through all the objects in the python interpreter) of deferreds. Please find it below as a shar archive (wow, someone still does those? Yeah, sometimes) Anyway, given a tree of deferreds, this will produce a whatever.dot file, which can be fed to graphviz' "dot -Tpdf whatever.dot > whatever.pdf", and the pdf has a rather nice-looking graph of the deferreds.<br>
<br>#!/bin/sh<br># This is a shell archive (produced by GNU sharutils 4.11.1).<br># To extract the files from this archive, save it to some FILE, remove<br># everything before the `#!/bin/sh' line above, then type `sh FILE'.<br>
#<br>lock_dir=_sh32156<br># Made on 2012-07-02 21:48 UTC by <stromberg@aw50>.<br># Source directory was `/home/stromberg/src/twisted-experiments'.<br>#<br># Existing files will *not* be overwritten, unless `-c' is specified.<br>
#<br># This shar contains:<br># length mode name<br># ------ ---------- ------------------------------------------<br># 2181 -rwxr-xr-x deferreddump.py<br># 3174 -rwxr-xr-x wedgedump<br>#<br>MD5SUM=${MD5SUM-md5sum}<br>
f=`${MD5SUM} --version | egrep '^md5sum .*(core|text)utils'`<br>test -n "${f}" && md5check=true || md5check=false<br>${md5check} || \<br> echo 'Note: not verifying md5sums. Consider installing GNU coreutils.'<br>
if test "X$1" = "X-c"<br>then keep_file=''<br>else keep_file=true<br>fi<br>echo=echo<br>save_IFS="${IFS}"<br>IFS="${IFS}:"<br>gettext_dir=<br>locale_dir=<br>set_echo=false<br>
<br>for dir in $PATH<br>do<br> if test -f $dir/gettext \<br> && ($dir/gettext --version >/dev/null 2>&1)<br> then<br> case `$dir/gettext --version 2>&1 | sed 1q` in<br> *GNU*) gettext_dir=$dir<br>
set_echo=true<br> break ;;<br> esac<br> fi<br>done<br><br>if ${set_echo}<br>then<br> set_echo=false<br> for dir in $PATH<br> do<br> if test -f $dir/shar \<br> && ($dir/shar --print-text-domain-dir >/dev/null 2>&1)<br>
then<br> locale_dir=`$dir/shar --print-text-domain-dir`<br> set_echo=true<br> break<br> fi<br> done<br><br> if ${set_echo}<br> then<br> TEXTDOMAINDIR=$locale_dir<br> export TEXTDOMAINDIR<br>
TEXTDOMAIN=sharutils<br> export TEXTDOMAIN<br> echo="$gettext_dir/gettext -s"<br> fi<br>fi<br>IFS="$save_IFS"<br>if (echo "testing\c"; echo 1,2,3) | grep c >/dev/null<br>then if (echo -n test; echo 1,2,3) | grep n >/dev/null<br>
then shar_n= shar_c='<br>'<br> else shar_n=-n shar_c= ; fi<br>else shar_n= shar_c='\c' ; fi<br>f=shar-touch.$$<br>st1=200112312359.59<br>st2=123123592001.59<br>st2tr=123123592001.5 # old SysV 14-char limit<br>
st3=1231235901<br><br>if touch -am -t ${st1} ${f} >/dev/null 2>&1 && \<br> test ! -f ${st1} && test -f ${f}; then<br> shar_touch='touch -am -t $1$2$3$4$5$6.$7 "$8"'<br><br>elif touch -am ${st2} ${f} >/dev/null 2>&1 && \<br>
test ! -f ${st2} && test ! -f ${st2tr} && test -f ${f}; then<br> shar_touch='touch -am $3$4$5$6$1$2.$7 "$8"'<br><br>elif touch -am ${st3} ${f} >/dev/null 2>&1 && \<br>
test ! -f ${st3} && test -f ${f}; then<br> shar_touch='touch -am $3$4$5$6$2 "$8"'<br><br>else<br> shar_touch=:<br> echo<br> ${echo} 'WARNING: not restoring timestamps. Consider getting and<br>
installing GNU `touch'\'', distributed in GNU coreutils...'<br> echo<br>fi<br>rm -f ${st1} ${st2} ${st2tr} ${st3} ${f}<br>#<br>if test ! -d ${lock_dir} ; then :<br>else ${echo} "lock directory ${lock_dir} exists"<br>
exit 1<br>fi<br>if mkdir ${lock_dir}<br>then ${echo} "x - created lock directory ${lock_dir}."<br>else ${echo} "x - failed to create lock directory ${lock_dir}."<br> exit 1<br>fi<br># ============= deferreddump.py ==============<br>
if test -n "${keep_file}" && test -f 'deferreddump.py'<br>then<br>${echo} "x - SKIPPING deferreddump.py (file already exists)"<br>else<br>${echo} "x - extracting deferreddump.py (text)"<br>
sed 's/^X//' << 'SHAR_EOF' > 'deferreddump.py' &&<br>#!/usr/bin/python<br>X<br># See also: <a href="http://twistedmatrix.com/trac/ticket/3858">http://twistedmatrix.com/trac/ticket/3858</a><br>
# and: <a href="http://twistedmatrix.com/trac/ticket/1402">http://twistedmatrix.com/trac/ticket/1402</a><br># and:<br># twisted.internet.defer also exposes a setDebugging(bool) function to<br># store call stacks from creation and invocation in deferred objects,<br>
# it's what I was using to try and figure out what was going on, but<br># it's not nearly as at-a-glance as a graph is.<br>X<br>import gc<br>import sys<br>X<br>import twisted.internet.defer<br>X<br>def escape(callback_type, obj):<br>
X dummy = callback_type<br>X return '%s' % (str(obj).replace(' ', '_').replace(':', '').replace('<', '').replace('>', ''), )<br>X<br>def dump(outfile = sys.stdout):<br>
X outfile.write('digraph deferred_digraph {\n')<br>X for obj in gc.get_objects():<br>X if isinstance(obj, twisted.internet.defer.Deferred):<br>X len_callbacks = len(obj.callbacks)<br>X if obj.callbacks:<br>
X outfile.write('\t%s -> %s\n' % (escape('', obj), escape('', obj.callbacks[0][0][0])))<br>X outfile.write('\t%s -> %s\n' % (escape('', obj), escape('', obj.callbacks[0][1][0])))<br>
X for callbackpairno in range(len_callbacks - 1):<br>X current_callback = obj.callbacks[callbackpairno][0]<br>X current_errback = obj.callbacks[callbackpairno][1]<br>X current_callback_desc = current_callback[0]<br>
X current_errback_desc = current_errback[0]<br>X<br>X next_callback = obj.callbacks[callbackpairno + 1][0]<br>X next_errback = obj.callbacks[callbackpairno + 1][1]<br>X next_callback_desc = next_callback[0]<br>
X next_errback_desc = next_errback[0]<br>X<br>X outfile.write('\t%s -> %s;\n' % (escape('callback', current_callback_desc), escape('callback', next_callback_desc)))<br>
X outfile.write('\t%s -> %s;\n' % (escape('errback', current_errback_desc), escape('errback', next_errback_desc)))<br>X<br>X outfile.write('\t%s -> %s;\n' % (escape('callback', current_callback_desc), escape('errback', next_errback_desc)))<br>
X outfile.write('\t%s -> %s;\n' % (escape('errback', current_errback_desc), escape('callback', next_callback_desc)))<br>X<br>X outfile.write('}\n')<br>X<br>X<br>SHAR_EOF<br>
(set 20 12 06 29 18 02 00 'deferreddump.py'<br> eval "${shar_touch}") && \<br> chmod 0755 'deferreddump.py'<br>if test $? -ne 0<br>then ${echo} "restore of deferreddump.py failed"<br>
fi<br> if ${md5check}<br> then (<br> ${MD5SUM} -c >/dev/null 2>&1 || ${echo} 'deferreddump.py': 'MD5 check failed'<br> ) << \SHAR_EOF<br>45b2aed37cc2e57bc58f46a42eb2a2d4 deferreddump.py<br>
SHAR_EOF<br> else<br>test `LC_ALL=C wc -c < 'deferreddump.py'` -ne 2181 && \<br> ${echo} "restoration warning: size of 'deferreddump.py' is not 2181"<br> fi<br>fi<br># ============= wedgedump ==============<br>
if test -n "${keep_file}" && test -f 'wedgedump'<br>then<br>${echo} "x - SKIPPING wedgedump (file already exists)"<br>else<br>${echo} "x - extracting wedgedump (text)"<br> sed 's/^X//' << 'SHAR_EOF' > 'wedgedump' &&<br>
#!/usr/bin/python<br>X<br># Unhandled Errors<br>X<br># From <a href="http://twistedmatrix.com/documents/current/core/howto/defer.html">http://twistedmatrix.com/documents/current/core/howto/defer.html</a> :<br>X<br># If a Deferred is garbage-collected with an unhandled error (i.e. it<br>
# would call the next errback if there was one), then Twisted will write<br># the error's traceback to the log file. This means that you can<br># typically get away with not adding errbacks and still get errors<br>
# logged. Be careful though; if you keep a reference to the Deferred<br># around, preventing it from being garbage-collected, then you may never<br># see the error (and your callbacks will mysteriously seem to have never<br>
# been called). If unsure, you should explicitly add an errback after<br># your callbacks, even if all you do is:<br>X<br># # Make sure errors get logged<br># from twisted.python import log<br># d.addErrback(log.err)<br>
X<br>import sys<br>#mport time<br>X<br>import twisted.internet.defer<br>import twisted.python<br>X<br>import deferreddump<br>X<br>def get_deferred():<br>X return twisted.internet.defer.succeed(1)<br>X<br>def cb1(value):<br>
X print value<br>X return value * 2<br>X<br>def cb2(value):<br>X #raise ValueError<br>X print value<br>X return value * 2<br>X<br>def cb3(value):<br>X print value<br>X return value * 2<br>X<br>def cb4(value):<br>
X print value<br>X return value * 2<br>X<br>def cb5(value):<br>X print value<br>X return value * 2<br>X<br>def cb6(value):<br>X print value<br>X return value * 2<br>X<br>def cb7(value):<br>X print value<br>
X return value * 2<br>X<br>def cb8(value):<br>X print value<br>X return value * 2<br>X<br>def eb1(value):<br>X twisted.python.log.err()<br>X<br>def eb2(value):<br>X twisted.python.log.err()<br>X<br>def eb3(value):<br>
X twisted.python.log.err()<br>X<br>def eb4(value):<br>X twisted.python.log.err()<br>X<br>def eb5(value):<br>X twisted.python.log.err()<br>X<br>def eb6(value):<br>X twisted.python.log.err()<br>X<br>def eb7(value):<br>
X twisted.python.log.err()<br>X<br>def eb8(value):<br>X twisted.python.log.err()<br>X<br>def arbitrary_function(add_final_log):<br>X deferred = get_deferred()<br>X<br>X # apparently we can use the same callback multiple times in the same deferred<br>
X first_deferred = deferred.addCallback(cb1)<br>X first_deferred.pause()<br>X deferred.addCallbacks(cb1, eb1)<br>X deferred.addCallbacks(cb2, eb2)<br>X deferred.addCallbacks(cb3, eb3)<br>X deferred.addCallbacks(cb4, eb4)<br>
X deferred.addCallbacks(cb5, eb5)<br>X deferred.addCallbacks(cb6, eb6)<br>X deferred.addCallbacks(cb7, eb7)<br>X<br>X with open('t.dot', 'w') as file_:<br>X deferreddump.dump(file_)<br>X<br>
X first_deferred.unpause()<br>X if add_final_log:<br>X deferred.addCallbacks(cb4, twisted.python.log.err)<br>X else:<br>X deferred.addCallback(cb4)<br>X<br>X return deferred<br>X<br>def usage(retval):<br>
X sys.stderr.write('Usage: %s --add-final-log\n' % sys.argv[0])<br>X sys.exit(retval)<br>X<br>def main():<br>X add_final_log = False<br>X while sys.argv[1:]:<br>X if sys.argv[1] == '--add-final-log':<br>
X add_final_log = True<br>X elif sys.argv[1] in [ '-h', '--help' ]:<br>X usage(0)<br>X else:<br>X sys.stderr.write('%s: Unrecognized option: %s\n' % (sys.argv[0], sys.argv[1]))<br>
X usage(1)<br>X del sys.argv[1]<br>X<br>X deferred = arbitrary_function(add_final_log)<br>X with open('/dev/null', 'w') as file_:<br>X file_.write(str(deferred))<br>X<br>X sys.exit(0)<br>
X<br>main()<br>X<br>SHAR_EOF<br> (set 20 12 07 02 21 46 02 'wedgedump'<br> eval "${shar_touch}") && \<br> chmod 0755 'wedgedump'<br>if test $? -ne 0<br>then ${echo} "restore of wedgedump failed"<br>
fi<br> if ${md5check}<br> then (<br> ${MD5SUM} -c >/dev/null 2>&1 || ${echo} 'wedgedump': 'MD5 check failed'<br> ) << \SHAR_EOF<br>d526664fcf63762f768303af91a74a5f wedgedump<br>
SHAR_EOF<br> else<br>test `LC_ALL=C wc -c < 'wedgedump'` -ne 3174 && \<br> ${echo} "restoration warning: size of 'wedgedump' is not 3174"<br> fi<br>fi<br>if rm -fr ${lock_dir}<br>then ${echo} "x - removed lock directory ${lock_dir}."<br>
else ${echo} "x - failed to remove lock directory ${lock_dir}."<br> exit 1<br>fi<br>exit 0<br><br>