[Twisted-web] profiling data and compy removal

Andrea Arcangeli andrea at cpushare.com
Thu Jan 20 18:43:22 MST 2005


On Thu, Jan 20, 2005 at 05:44:55PM +0100, Andrea Arcangeli wrote:
> My profiling shows the interface layer (getInterfaces paths) to be one

Here the data ordered by number of calls:

         2136207 function calls (1831320 primitive calls) in 13.037 CPU seconds
   222020    0.154    0.000    0.154    0.000 interface.py:250(<lambda>)
186611/80181    1.451    0.000    1.608    0.000 interface.py:276(interfaces)
   107577    0.087    0.000    0.094    0.000 components.py:163(fixClassImplements)
97126/41704    0.903    0.000   10.819    0.000 flatstan.py:29(TagSerializer)
    93040    0.064    0.000    0.064    0.000 stan.py:381(getSpecial)
    92590    0.470    0.000    0.583    0.000 warnings.py:24(warn)
    92590    0.113    0.000    0.113    0.000 warnings.py:59(warn_explicit)
    80170    0.221    0.000    0.221    0.000 util.py:206(uniquify)
    68463    0.259    0.000    0.259    0.000 declarations.py:82(__iter__)
68461/23048    0.332    0.000   10.640    0.000 ten.py:74(partialflatten)
    68461    1.279    0.000    4.370    0.000 components.py:387(getInterfaces)
    68461    0.310    0.000    4.753    0.000 ten.py:43(getFlattener)
65326/22920    0.167    0.000   10.686    0.000 ten.py:89(serialize)
    36796    0.025    0.000    0.025    0.000 interface.py:531(direct)
    34483    0.024    0.000    0.024    0.000 flatstan.py:119(StringSerializer)
    31376    0.084    0.000    0.084    0.000 context.py:49(__init__)
    31088    0.498    0.000    0.609    0.000 context.py:275(__init__)
    26159    0.177    0.000    0.177    0.000 util.py:64(qual)
    23436    0.035    0.000    0.035    0.000 interface.py:458(interfaces)
23420/11710    0.218    0.000    0.250    0.000 reflect.py:464(accumulateBases)
    22947    0.068    0.000    0.084    0.000 pyexpat.c:461(CharacterData)
    22947    0.015    0.000    0.015    0.000 flatsax.py:159(characters)
22398/15854    0.666    0.000    2.252    0.000 components.py:283(__call__)
    18448    0.084    0.000    0.522    0.000 interface.py:706(__adapt__)
    18357    0.068    0.000    1.627    0.000 flatstan.py:143(ListSerializer)
    17967    0.099    0.000    0.636    0.000 interface.py:609(__call__)
    16976    0.033    0.000    0.033    0.000 stan.py:374(__nonzero__)
    16096    0.083    0.000    0.083    0.000 interface.py:355(weakref)
16075/16046    0.091    0.000    0.176    0.000 adapter.py:470(get)
    16046    0.081    0.000    0.326    0.000 adapter.py:383(lookup1)
    16046    0.080    0.000    0.437    0.000 components.py:110(_hook)
    16046    0.066    0.000    0.245    0.000 adapter.py:314(lookup)
14621/14606    0.185    0.000    0.464    0.000 components.py:343(__getattr__)
    14606    0.188    0.000    0.213    0.000 interface.py:362(get)
    14606    0.066    0.000    0.279    0.000 interface.py:534(queryDescriptionFor)
    13560    0.095    0.000    0.095    0.000 stan.py:137(__init__)
    11710    0.048    0.000    0.298    0.000 reflect.py:454(allYourBase)
    11709    0.146    0.000    0.540    0.000 components.py:407(superInterfaces)
11328/2208    0.188    0.000    0.536    0.000 context.py:160(clone)
11328/2208    0.089    0.000    0.557    0.000 context.py:327(clone)
    10912    0.133    0.000    1.378    0.000 context.py:78(locate)
    10672    0.086    0.000    1.166    0.000 context.py:200(locateHook)
    10580    0.168    0.000    0.168    0.000 weakref.py:67(has_key)
9540/1431    0.099    0.000    0.102    0.000 stan.py:475(specialMatches)


here the cumulative time for each single call:

186611/80181    1.451    0.000    1.608    0.000 interface.py:276(interfaces)
    68461    1.279    0.000    4.370    0.000 components.py:387(getInterfaces)
97126/41704    0.903    0.000   10.819    0.000 flatstan.py:29(TagSerializer)
22398/15854    0.666    0.000    2.252    0.000 components.py:283(__call__)
       80    0.627    0.008   12.910    0.161 pollreactor.py:114(doPoll)
    31088    0.498    0.000    0.609    0.000 context.py:275(__init__)
    92590    0.470    0.000    0.583    0.000 warnings.py:24(warn)
68461/23048    0.332    0.000   10.640    0.000 ten.py:74(partialflatten)
    68461    0.310    0.000    4.753    0.000 ten.py:43(getFlattener)
    68463    0.259    0.000    0.259    0.000 declarations.py:82(__iter__)
     7502    0.248    0.000    0.336    0.000 flatsax.py:99(startElementNS)
    80170    0.221    0.000    0.221    0.000 util.py:206(uniquify)
23420/11710    0.218    0.000    0.250    0.000 reflect.py:464(accumulateBases)
 3155/137    0.206    0.000   11.891    0.087 ten.py:94(iterflatten)
    14606    0.188    0.000    0.213    0.000 interface.py:362(get)
11328/2208    0.188    0.000    0.536    0.000 context.py:160(clone)
14621/14606    0.185    0.000    0.464    0.000 components.py:343(__getattr__)
    26159    0.177    0.000    0.177    0.000 util.py:64(qual)
    10580    0.168    0.000    0.168    0.000 weakref.py:67(has_key)
65326/22920    0.167    0.000   10.686    0.000 ten.py:89(serialize)
      390    0.159    0.000    0.868    0.002 expatreader.py:196(feed)
   222020    0.154    0.000    0.154    0.000 interface.py:250(<lambda>)
    11709    0.146    0.000    0.540    0.000 components.py:407(superInterfaces)
    10912    0.133    0.000    1.378    0.000 context.py:78(locate)
    92590    0.113    0.000    0.113    0.000 warnings.py:59(warn_explicit)
     7502    0.110    0.000    0.469    0.000 expatreader.py:305(start_element_ns)
9540/1431    0.099    0.000    0.102    0.000 stan.py:475(specialMatches)
    17967    0.099    0.000    0.636    0.000 interface.py:609(__call__)
    13560    0.095    0.000    0.095    0.000 stan.py:137(__init__)
3096/2904    0.093    0.000    7.906    0.003 flatstan.py:170(FunctionSerializer)
16075/16046    0.091    0.000    0.176    0.000 adapter.py:470(get)
11328/2208    0.089    0.000    0.557    0.000 context.py:327(clone)
   107577    0.087    0.000    0.094    0.000 components.py:163(fixClassImplements)
7290/4622    0.086    0.000    0.743    0.000 accessors.py:22(convertToData)
    10672    0.086    0.000    1.166    0.000 context.py:200(locateHook)
    31376    0.084    0.000    0.084    0.000 context.py:49(__init__)
    18448    0.084    0.000    0.522    0.000 interface.py:706(__adapt__)
    16096    0.083    0.000    0.083    0.000 interface.py:355(weakref)
    16046    0.081    0.000    0.326    0.000 adapter.py:383(lookup1)
    16046    0.080    0.000    0.437    0.000 components.py:110(_hook)
     5757    0.072    0.000    0.118    0.000 stan.py:315(clone)
    22947    0.068    0.000    0.084    0.000 pyexpat.c:461(CharacterData)
    18357    0.068    0.000    1.627    0.000 flatstan.py:143(ListSerializer)
    16046    0.066    0.000    0.245    0.000 adapter.py:314(lookup)
    14606    0.066    0.000    0.279    0.000 interface.py:534(queryDescriptionFor)
      960    0.064    0.000    0.311    0.000 server.py:337(_prePathURL)
    93040    0.064    0.000    0.064    0.000 stan.py:381(getSpecial)
     2904    0.060    0.000    8.243    0.003 flatstan.py:209(DirectiveSerializer)

As noted by dialtone privately even the warning code hurts
significantly. The simple change I attacehd below raises the number of
pages per second from 4.9 to 5.81.  The time per request goes from 203
to 172. So I stand by my argument that the interfaces are by far the
worst offender, even worse than the rendering itself. And there's zero
formless in the page I'm benchmarking above, that's the home page with
the __login__ form done by hand (with some render call to get dynamic
links to https but no formless).

So to me even the below one liner is a significant measurable
optimization. If this bit makes so much difference you can only imagine
how much we can optimize by dropping getInterfaces.

Personally I think the first priority in nevow is to drop the compy
thing and do it with zope.interfaces and see what kind of improvement we
get. I would hope there's a way to keep a compatibility module for
formless until it learns about zope.interfaces too. I don't care that
much about the speed of formless, formless can keep using a
compatibility wrapper and be slow, but the page I used above makes zero
use of formless and it should be faster than 203/172 msec. At the very
least by dropping the warning the right way, we'll get a speedup from
203 to 172 msec for the rendering of my pages, since it won't require
the obsolete-warning anymore 8). This of course assumes the
zope.interfaces are being implemented sanely without O(N) loops over
tuples to find if the instance implements an interface. If they're
implemented in C even better.

Below patch is not meant to be applied of course.

--- ./lib/python2.4/site-packages/twisted/python/components.py.~1~	2005-01-14 20:44:44.000000000 +0100
+++ ./lib/python2.4/site-packages/twisted/python/components.py	2005-01-21 02:28:57.245648664 +0100
@@ -389,7 +389,7 @@ def getInterfaces(klass):
 
     This is horrible and stupid. Please use zope.interface.providedBy() or implementedBy().
     """
-    warnings.warn("getInterfaces should not be used, use providedBy() or implementedBy()", ComponentsDeprecationWarning, stacklevel=2)
+#    warnings.warn("getInterfaces should not be used, use providedBy() or implementedBy()", ComponentsDeprecationWarning, stacklevel=2)
     # try to support both classes and instances, giving different behaviour
     # which is HORRIBLE :(
     if isinstance(klass, (type, types.ClassType)):



More information about the Twisted-web mailing list