[Twisted-Python] deferred graph?

Dan Stromberg drsalists at gmail.com
Mon Jul 2 20:31:14 EDT 2012


On Thu, Jun 28, 2012 at 9:40 PM, Dan Stromberg <drsalists at 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 at 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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://twistedmatrix.com/pipermail/twisted-python/attachments/20120703/25ad2826/attachment.htm 


More information about the Twisted-Python mailing list