How slow should dtml-var be? (was: RE: [Zope] Problems with *BIG* SQL queries)
As mentioned, I'm doing really big SQL queries which return a HTML report that's about 1Mb. The ZopeTime trick suggested by Alan helps a lot - the time spent really is on the Zope side, and happens even with the most minimal file - just a: <dtml-var "ZopeTime()"> <dtml-in QUERY> <dtml-var column1>,<dtml-var column2>,<dtml-var column3>,<dtml-var column4> </dtml-in> <dtml-var "ZopeTime()"> This takes about 4 minutes *on the server* - file return is quick. *Sigh*. This however: <dtml-var "ZopeTime()"> <dtml-in QUERY> </dtml-in> <dtml-var "ZopeTime()"> Takes about 30 seconds (which is reasonable): HTTP/1.1 200 OK Date: Wed, 21 Mar 2001 14:02:07 GMT Server: Apache/1.3.14 (Unix) (Red-Hat/Linux) X-Powered-By: Zope (www.zope.org), Python (www.python.org) Vary: Authorization Content-Length: 94 Connection: close Content-Type: text/plain 2001/03/21 14:02:07.2783 GMT 2001/03/21 14:02:46.6733 GMT I can only assume it's the namespace lookup in <dtml-var variable> - in fact, my calculations (9575 rows, 4 <dtml-var>s per row) make that 6ms per dtml-var, which isn't unreasonable. I guess I really do just have too much data... Using a PythonScript: print context.ZopeTime() for result in container.QUERY(): print "%s,%s,%s,%s" % (r.column1,r.column2,r.column3,r.column4) print context.ZopeTime() return printed ...doesn't seem to help Regards, Phil +----------------------------------+ | Phil Mayers, Network Support | | Centre for Computing Services | | Imperial College | +----------------------------------+
Yup sounds like its too much data, one thing that can vary of course is rendering on the browser, large pages can take a long time just to be rendered, for example lots of tables on Netscape. Your example includes no HTML so thats just an off the wall comment. -- Andy McKay. ----- Original Message ----- From: "Mayers, Philip J" <p.mayers@ic.ac.uk> To: "'Capesius, Alan'" <CapesiusA@Sysmex.com>; <zope@zope.org> Sent: Wednesday, March 21, 2001 6:16 AM Subject: How slow should dtml-var be? (was: RE: [Zope] Problems with *BIG* SQL queries)
As mentioned, I'm doing really big SQL queries which return a HTML report that's about 1Mb. The ZopeTime trick suggested by Alan helps a lot - the time spent really is on the Zope side, and happens even with the most minimal file - just a:
<dtml-var "ZopeTime()"> <dtml-in QUERY> <dtml-var column1>,<dtml-var column2>,<dtml-var column3>,<dtml-var column4> </dtml-in> <dtml-var "ZopeTime()">
This takes about 4 minutes *on the server* - file return is quick. *Sigh*. This however:
<dtml-var "ZopeTime()"> <dtml-in QUERY> </dtml-in> <dtml-var "ZopeTime()">
Takes about 30 seconds (which is reasonable):
HTTP/1.1 200 OK Date: Wed, 21 Mar 2001 14:02:07 GMT Server: Apache/1.3.14 (Unix) (Red-Hat/Linux) X-Powered-By: Zope (www.zope.org), Python (www.python.org) Vary: Authorization Connection: close Content-Type: text/plain
2001/03/21 14:02:07.2783 GMT 2001/03/21 14:02:46.6733 GMT
I can only assume it's the namespace lookup in <dtml-var variable> - in fact, my calculations (9575 rows, 4 <dtml-var>s per row) make that 6ms per dtml-var, which isn't unreasonable. I guess I really do just have too much data...
Using a PythonScript:
print context.ZopeTime() for result in container.QUERY(): print "%s,%s,%s,%s" % (r.column1,r.column2,r.column3,r.column4) print context.ZopeTime() return printed
...doesn't seem to help
Regards, Phil
+----------------------------------+ | Phil Mayers, Network Support | | Centre for Computing Services | | Imperial College | +----------------------------------+
_______________________________________________ Zope maillist - Zope@zope.org http://lists.zope.org/mailman/listinfo/zope ** No cross posts or HTML encoding! ** (Related lists - http://lists.zope.org/mailman/listinfo/zope-announce http://lists.zope.org/mailman/listinfo/zope-dev )
here's something that will probably help: push it into an external method. mymethod.py (untested): import string def mymethod(self): log = [] log.append(self.ZopeTime()) for r in self.QUERY(): log.append(%s,%s,%s,%s" % (r.column1,r.column2,r.column3,r.column4)) log.append(self.ZopeTime()) return string.join(log, '\n') ...and run it from the "test" tab after instantiating the external method object. the time *should* improve considerably. jens
Using a PythonScript:
print context.ZopeTime() for result in container.QUERY(): print "%s,%s,%s,%s" % (r.column1,r.column2,r.column3,r.column4) print context.ZopeTime() return printed
...doesn't seem to help
Phil, one thing I'd recommend is consider using an external method to create your report; you might be pleasantly surprised. This means, instead of <dtml-in QUERY> <dtml-var ...> (etc) </dtml-in> You do a <dtml-var expr="myExMeth(REQUEST, QUERY)"> And your external method gets the REQUEST and QUERY objects to do its thing, format the results, and return it as one big item. It might *significantly* cut down on your time, since what's killing you is <dtml-var> * 38300. For the performance minded, it's informative to do things like run ab against a blank dtml method, then one with one dtml-var, then two, etc... On a 1Ghz CPU, it seems like you can get at least 180tps without any dtml-vars, then about 166 with 1, then about 150 with 2, etc... I think (I'm going by memory) that this translates to about 5.5 million 386 cycles for Zope to serve a page, and about an extra 500,000 cycles per dtml-var. Your milage may vary, of course. If I'm right, that would be about 19.1 billion cycles to render your page of 38300 dtml-vars. Thats about 19 sec on a 1GHz CPU (or about 5.3 hours on an Apple ][), but you'd loose some time to system overhead, and if you're if you're on a 200MHz machine, you're talking about 19 * 5 or 100 sec. Given that you're reporting that the query itself takes 30 seconds, if you subtract that from your 4 minutes, you get about 210 seconds left, so I'm only wrong by a factor of two. Which is pretty good for my guesstimates (I normally consider "good" to be within 4X on a guess.) The moral of the story is dynamic is good, but let's be reasonably dynamic :) It also suggests that there's an area where large SQL processing/table generation should be moved out of python for faster rendering. "Mayers, Philip J" wrote:
As mentioned, I'm doing really big SQL queries which return a HTML report that's about 1Mb. The ZopeTime trick suggested by Alan helps a lot - the time spent really is on the Zope side, and happens even with the most minimal file - just a:
<dtml-var "ZopeTime()"> <dtml-in QUERY> <dtml-var column1>,<dtml-var column2>,<dtml-var column3>,<dtml-var column4> </dtml-in> <dtml-var "ZopeTime()">
This takes about 4 minutes *on the server* - file return is quick. *Sigh*. This however:
<dtml-var "ZopeTime()"> <dtml-in QUERY> </dtml-in> <dtml-var "ZopeTime()">
Takes about 30 seconds (which is reasonable):
HTTP/1.1 200 OK Date: Wed, 21 Mar 2001 14:02:07 GMT Server: Apache/1.3.14 (Unix) (Red-Hat/Linux) X-Powered-By: Zope (www.zope.org), Python (www.python.org) Vary: Authorization Content-Length: 94 Connection: close Content-Type: text/plain
2001/03/21 14:02:07.2783 GMT 2001/03/21 14:02:46.6733 GMT
I can only assume it's the namespace lookup in <dtml-var variable> - in fact, my calculations (9575 rows, 4 <dtml-var>s per row) make that 6ms per dtml-var, which isn't unreasonable. I guess I really do just have too much data...
Using a PythonScript:
print context.ZopeTime() for result in container.QUERY(): print "%s,%s,%s,%s" % (r.column1,r.column2,r.column3,r.column4) print context.ZopeTime() return printed
...doesn't seem to help
Regards, Phil
On 23/3/01 2:40 pm, "Matthew T. Kromer" <matt@digicool.com> wrote:
Phil, one thing I'd recommend is consider using an external method to create your report; you might be pleasantly surprised.
This means, instead of
<dtml-in QUERY> <dtml-var ...> (etc) </dtml-in>
You do a <dtml-var expr="myExMeth(REQUEST, QUERY)">
And your external method gets the REQUEST and QUERY objects to do its thing, format the results, and return it as one big item.
It might *significantly* cut down on your time, since what's killing you is <dtml-var> * 38300.
This is very interesting. Do any DC gurus have anything to say on this? I also agree that offloading things like summations onto your SQL database is a *good thing*. Tone. -- Dr Tony McDonald, Assistant Director, FMCC, http://www.fmcc.org.uk/ The Medical School, Newcastle University Tel: +44 191 243 6140 A Zope list for UK HE/FE http://www.fmcc.org.uk/mailman/listinfo/zope
participants (5)
-
Andy McKay -
Jens Vagelpohl -
Matthew T. Kromer -
Mayers, Philip J -
Tony McDonald