[Zope-dev] remote procedure calls to manage functions
Jim Fulton
jim@digicool.com
Thu, 10 Aug 2000 08:21:51 -0400
Michel Pelletier wrote:
>
> Jim Fulton wrote:
> >
> > Michel Pelletier wrote:
> > >
(snip)
> > > Also, ZClient
> > > is much faster i've found, probably due to the marshalling/unmarshalling
> > > necessary for xml-rpc.
> >
> > That's interesting......Hm. ZClient has to marshal. I suspect that
> > xml-rpc wants some sort of optimization.
>
> I made a test script to make about 300 xmlrpc calls to various manage_
> methods. I had to kill it after about a half-hour cuz it was takin so
> long.
This sounds pretty fishy. Are you saying that you made less than
300 calls in half an hour? This doesn't seem right at all.
> Here's the profiler output:
>
> ncalls tottime percall cumtime percall filename:lineno(function)
> 702883/2151 108.980 0.000 288.580 0.134
> DT_InSV.py:379(__getitem__)
> 7704 79.050 0.010 243.900 0.032 xmllib.py:201(goahead)
> 3852 42.300 0.011 43.160 0.011
> FileStorage.py:706(_finish)
Hm. This says that the FileStorage _finish method was called
3852 times. This says that 3852 transactions were committed.
Since transactions only get committed on write requests, then
this suggests 3852 write requests. There should have been
way more than 3852 requests to have this many write requests.....
> 158831/158827 38.010 0.000 70.140 0.000 DT_Var.py:258(render)
> 732178 37.580 0.000 49.450 0.000 re.py:112(match)
> 495239/51912 36.690 0.000 307.200 0.006
> HTTPRequest.py:741(__getitem__)
> 586827 29.040 0.000 29.040 0.000 re.py:335(group)
> 499291 22.900 0.000 30.530 0.000 re.py:95(search)
> 875347 19.500 0.000 19.500 0.000 re.py:290(__init__)
> 45981 14.090 0.000 39.000 0.001
> xmllib.py:539(parse_starttag)
> 748592 10.680 0.000 10.680 0.000 exceptions.py:65(__init__)
> 541924 9.420 0.000 9.420 0.000 re.py:297(start)
> 456273 9.190 0.000 9.190 0.000 re.py:306(end)
> 107831 8.520 0.000 8.520 0.000 urllib.py:898(quote)
> 127647/10757 7.400 0.000 300.080 0.028 :0(?)
> 49113 7.160 0.000 8.240 0.000
> User.py:140(getRolesInContext)
> 127647/4302 6.350 0.000 303.910 0.071 DT_Util.py:325(eval)
> 45981 5.360 0.000 19.870 0.000
> xmllib.py:615(parse_endtag)
> 111258 5.240 0.000 7.030 0.000
> xmllib.py:699(handle_charref)
> 3856 5.100 0.001 17.020 0.004
> BaseRequest.py:224(traverse)
> 284515 4.510 0.000 4.510 0.000 xmlrpclib.py:387(data)
>
> I think you're right about optimizing, why is it spending most of it's
> time in DT_InSV?
First, it's not spending most of it's time in DT_InSV __getitem__, although
it's spending more time in that method than in any other single method.
The reason it spends so much time in that method is that the method
gets called 700 thousand times. That is, it's used alot, because alot
of in-tag special variables are used in your test. This is also a
pretty non-trivial method, so it's reasonable that it might take
a while.
All of this seems to me to be somewhat beside the point.
The original comment was regarding ZClient vs XML-RPC.
It would be more interesting to:
- Compare ZClient and XML-RPC for some realistic tests, like yours,
- Compare them for simple Python methods that don't do much but
return some data, something like:
def test(x,y,z):
return 'hello world' * 100
- If there is a big difference, use the profiler to try to figure out
why XML-RPC is taking so long.
Jim
--
Jim Fulton mailto:jim@digicool.com Python Powered!
Technical Director (888) 344-4332 http://www.python.org
Digital Creations http://www.digicool.com http://www.zope.org
Under US Code Title 47, Sec.227(b)(1)(C), Sec.227(a)(2)(B) This email
address may not be added to any commercial mail list with out my
permission. Violation of my privacy with advertising or SPAM will
result in a suit for a MINIMUM of $500 damages/incident, $1500 for
repeats.