On Thu, Jun 28, 2012 at 9:40 PM, Dan Stromberg <drsali...@gmail.com> wrote:
>
> Hi.
>
> I'm a Twisted neophyte, but I've been using Python a long time.
>
> My question:
> 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.
>
>
> Background:
> I'm looking at some code with a bit over 200
> addCallback/addErrback/addCallbacks in it.
>
> 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.
>
> 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.
>
>
> Thanks!
>
> 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.
#!/bin/sh
# This is a shell archive (produced by GNU sharutils 4.11.1).
# To extract the files from this archive, save it to some FILE, remove
# everything before the `#!/bin/sh' line above, then type `sh FILE'.
#
lock_dir=_sh32156
# Made on 2012-07-02 21:48 UTC by <stromberg@aw50>.
# Source directory was `/home/stromberg/src/twisted-experiments'.
#
# Existing files will *not* be overwritten, unless `-c' is specified.
#
# This shar contains:
# length mode name
# ------ ---------- ------------------------------------------
# 2181 -rwxr-xr-x deferreddump.py
# 3174 -rwxr-xr-x wedgedump
#
MD5SUM=${MD5SUM-md5sum}
f=`${MD5SUM} --version | egrep '^md5sum .*(core|text)utils'`
test -n "${f}" && md5check=true || md5check=false
${md5check} || \
echo 'Note: not verifying md5sums. Consider installing GNU coreutils.'
if test "X$1" = "X-c"
then keep_file=''
else keep_file=true
fi
echo=echo
save_IFS="${IFS}"
IFS="${IFS}:"
gettext_dir=
locale_dir=
set_echo=false
for dir in $PATH
do
if test -f $dir/gettext \
&& ($dir/gettext --version >/dev/null 2>&1)
then
case `$dir/gettext --version 2>&1 | sed 1q` in
*GNU*) gettext_dir=$dir
set_echo=true
break ;;
esac
fi
done
if ${set_echo}
then
set_echo=false
for dir in $PATH
do
if test -f $dir/shar \
&& ($dir/shar --print-text-domain-dir >/dev/null 2>&1)
then
locale_dir=`$dir/shar --print-text-domain-dir`
set_echo=true
break
fi
done
if ${set_echo}
then
TEXTDOMAINDIR=$locale_dir
export TEXTDOMAINDIR
TEXTDOMAIN=sharutils
export TEXTDOMAIN
echo="$gettext_dir/gettext -s"
fi
fi
IFS="$save_IFS"
if (echo "testing\c"; echo 1,2,3) | grep c >/dev/null
then if (echo -n test; echo 1,2,3) | grep n >/dev/null
then shar_n= shar_c='
'
else shar_n=-n shar_c= ; fi
else shar_n= shar_c='\c' ; fi
f=shar-touch.$$
st1=200112312359.59
st2=123123592001.59
st2tr=123123592001.5 # old SysV 14-char limit
st3=1231235901
if touch -am -t ${st1} ${f} >/dev/null 2>&1 && \
test ! -f ${st1} && test -f ${f}; then
shar_touch='touch -am -t $1$2$3$4$5$6.$7 "$8"'
elif touch -am ${st2} ${f} >/dev/null 2>&1 && \
test ! -f ${st2} && test ! -f ${st2tr} && test -f ${f}; then
shar_touch='touch -am $3$4$5$6$1$2.$7 "$8"'
elif touch -am ${st3} ${f} >/dev/null 2>&1 && \
test ! -f ${st3} && test -f ${f}; then
shar_touch='touch -am $3$4$5$6$2 "$8"'
else
shar_touch=:
echo
${echo} 'WARNING: not restoring timestamps. Consider getting and
installing GNU `touch'\'', distributed in GNU coreutils...'
echo
fi
rm -f ${st1} ${st2} ${st2tr} ${st3} ${f}
#
if test ! -d ${lock_dir} ; then :
else ${echo} "lock directory ${lock_dir} exists"
exit 1
fi
if mkdir ${lock_dir}
then ${echo} "x - created lock directory ${lock_dir}."
else ${echo} "x - failed to create lock directory ${lock_dir}."
exit 1
fi
# ============= deferreddump.py ==============
if test -n "${keep_file}" && test -f 'deferreddump.py'
then
${echo} "x - SKIPPING deferreddump.py (file already exists)"
else
${echo} "x - extracting deferreddump.py (text)"
sed 's/^X//' << 'SHAR_EOF' > 'deferreddump.py' &&
#!/usr/bin/python
X
# See also: http://twistedmatrix.com/trac/ticket/3858
# and: http://twistedmatrix.com/trac/ticket/1402
# and:
# twisted.internet.defer also exposes a setDebugging(bool) function to
# store call stacks from creation and invocation in deferred objects,
# it's what I was using to try and figure out what was going on, but
# it's not nearly as at-a-glance as a graph is.
X
import gc
import sys
X
import twisted.internet.defer
X
def escape(callback_type, obj):
X dummy = callback_type
X return '%s' % (str(obj).replace(' ', '_').replace(':',
'').replace('<', '').replace('>', ''), )
X
def dump(outfile = sys.stdout):
X outfile.write('digraph deferred_digraph {\n')
X for obj in gc.get_objects():
X if isinstance(obj, twisted.internet.defer.Deferred):
X len_callbacks = len(obj.callbacks)
X if obj.callbacks:
X outfile.write('\t%s -> %s\n' % (escape('', obj),
escape('', obj.callbacks[0][0][0])))
X outfile.write('\t%s -> %s\n' % (escape('', obj),
escape('', obj.callbacks[0][1][0])))
X for callbackpairno in range(len_callbacks - 1):
X current_callback = obj.callbacks[callbackpairno][0]
X current_errback = obj.callbacks[callbackpairno][1]
X current_callback_desc = current_callback[0]
X current_errback_desc = current_errback[0]
X
X next_callback = obj.callbacks[callbackpairno + 1][0]
X next_errback = obj.callbacks[callbackpairno + 1][1]
X next_callback_desc = next_callback[0]
X next_errback_desc = next_errback[0]
X
X outfile.write('\t%s -> %s;\n' % (escape('callback',
current_callback_desc), escape('callback', next_callback_desc)))
X outfile.write('\t%s -> %s;\n' % (escape('errback',
current_errback_desc), escape('errback', next_errback_desc)))
X
X outfile.write('\t%s -> %s;\n' % (escape('callback',
current_callback_desc), escape('errback', next_errback_desc)))
X outfile.write('\t%s -> %s;\n' % (escape('errback',
current_errback_desc), escape('callback', next_callback_desc)))
X
X outfile.write('}\n')
X
X
SHAR_EOF
(set 20 12 06 29 18 02 00 'deferreddump.py'
eval "${shar_touch}") && \
chmod 0755 'deferreddump.py'
if test $? -ne 0
then ${echo} "restore of deferreddump.py failed"
fi
if ${md5check}
then (
${MD5SUM} -c >/dev/null 2>&1 || ${echo} 'deferreddump.py': 'MD5
check failed'
) << \SHAR_EOF
45b2aed37cc2e57bc58f46a42eb2a2d4 deferreddump.py
SHAR_EOF
else
test `LC_ALL=C wc -c < 'deferreddump.py'` -ne 2181 && \
${echo} "restoration warning: size of 'deferreddump.py' is not 2181"
fi
fi
# ============= wedgedump ==============
if test -n "${keep_file}" && test -f 'wedgedump'
then
${echo} "x - SKIPPING wedgedump (file already exists)"
else
${echo} "x - extracting wedgedump (text)"
sed 's/^X//' << 'SHAR_EOF' > 'wedgedump' &&
#!/usr/bin/python
X
# Unhandled Errors
X
# From http://twistedmatrix.com/documents/current/core/howto/defer.html :
X
# If a Deferred is garbage-collected with an unhandled error (i.e. it
# would call the next errback if there was one), then Twisted will write
# the error's traceback to the log file. This means that you can
# typically get away with not adding errbacks and still get errors
# logged. Be careful though; if you keep a reference to the Deferred
# around, preventing it from being garbage-collected, then you may never
# see the error (and your callbacks will mysteriously seem to have never
# been called). If unsure, you should explicitly add an errback after
# your callbacks, even if all you do is:
X
# # Make sure errors get logged
# from twisted.python import log
# d.addErrback(log.err)
X
import sys
#mport time
X
import twisted.internet.defer
import twisted.python
X
import deferreddump
X
def get_deferred():
X return twisted.internet.defer.succeed(1)
X
def cb1(value):
X print value
X return value * 2
X
def cb2(value):
X #raise ValueError
X print value
X return value * 2
X
def cb3(value):
X print value
X return value * 2
X
def cb4(value):
X print value
X return value * 2
X
def cb5(value):
X print value
X return value * 2
X
def cb6(value):
X print value
X return value * 2
X
def cb7(value):
X print value
X return value * 2
X
def cb8(value):
X print value
X return value * 2
X
def eb1(value):
X twisted.python.log.err()
X
def eb2(value):
X twisted.python.log.err()
X
def eb3(value):
X twisted.python.log.err()
X
def eb4(value):
X twisted.python.log.err()
X
def eb5(value):
X twisted.python.log.err()
X
def eb6(value):
X twisted.python.log.err()
X
def eb7(value):
X twisted.python.log.err()
X
def eb8(value):
X twisted.python.log.err()
X
def arbitrary_function(add_final_log):
X deferred = get_deferred()
X
X # apparently we can use the same callback multiple times in the same
deferred
X first_deferred = deferred.addCallback(cb1)
X first_deferred.pause()
X deferred.addCallbacks(cb1, eb1)
X deferred.addCallbacks(cb2, eb2)
X deferred.addCallbacks(cb3, eb3)
X deferred.addCallbacks(cb4, eb4)
X deferred.addCallbacks(cb5, eb5)
X deferred.addCallbacks(cb6, eb6)
X deferred.addCallbacks(cb7, eb7)
X
X with open('t.dot', 'w') as file_:
X deferreddump.dump(file_)
X
X first_deferred.unpause()
X if add_final_log:
X deferred.addCallbacks(cb4, twisted.python.log.err)
X else:
X deferred.addCallback(cb4)
X
X return deferred
X
def usage(retval):
X sys.stderr.write('Usage: %s --add-final-log\n' % sys.argv[0])
X sys.exit(retval)
X
def main():
X add_final_log = False
X while sys.argv[1:]:
X if sys.argv[1] == '--add-final-log':
X add_final_log = True
X elif sys.argv[1] in [ '-h', '--help' ]:
X usage(0)
X else:
X sys.stderr.write('%s: Unrecognized option: %s\n' %
(sys.argv[0], sys.argv[1]))
X usage(1)
X del sys.argv[1]
X
X deferred = arbitrary_function(add_final_log)
X with open('/dev/null', 'w') as file_:
X file_.write(str(deferred))
X
X sys.exit(0)
X
main()
X
SHAR_EOF
(set 20 12 07 02 21 46 02 'wedgedump'
eval "${shar_touch}") && \
chmod 0755 'wedgedump'
if test $? -ne 0
then ${echo} "restore of wedgedump failed"
fi
if ${md5check}
then (
${MD5SUM} -c >/dev/null 2>&1 || ${echo} 'wedgedump': 'MD5 check
failed'
) << \SHAR_EOF
d526664fcf63762f768303af91a74a5f wedgedump
SHAR_EOF
else
test `LC_ALL=C wc -c < 'wedgedump'` -ne 3174 && \
${echo} "restoration warning: size of 'wedgedump' is not 3174"
fi
fi
if rm -fr ${lock_dir}
then ${echo} "x - removed lock directory ${lock_dir}."
else ${echo} "x - failed to remove lock directory ${lock_dir}."
exit 1
fi
exit 0
_______________________________________________
Twisted-Python mailing list
Twisted-Python@twistedmatrix.com
http://twistedmatrix.com/cgi-bin/mailman/listinfo/twisted-python
