lovely jukart and dobee - Still on (double) speed.
Here is a short story about a lovely executive report about what lovely people like Jürgen (jukart) and Bernd (dobee) are doing on an average friday :) They made some changes in the zope.security package:
——————–
While deploying the first egg based portal using zc.buildout we found that idle lovely.remotetasks caused a CPU load of 5% despite doing nothing.
After some investigation with the profiler:
lovely.remotetask throws an IndexError exception if there is no job to do. It is doing this once a second.
The publisher gets a traceback for the exception using python’s traceback module.
traceback.extract_stack() uses python’s linecache module.
Now here is the problem:
linecache is extremely slow when using eggs. We could measure 54 ms for the time spent in the zope publisher!
So we changed remotetask to not throw an IndexError.
But the publisher still took 27ms.
Profiling again showed us that traceback.extract_stack() was still called somewhere.
Finally we found it in zope.security.manager.py
newInteraction was storing a traceback to be able to print a nice traceback in case newInteraction is called a second time. This is really a good thing for the developer because you get a very detailed error report which shows you exactly from where newInteraction was called the first time.
But for which price:
Removing the extraction of the traceback put down the publisher time to
2ms
So we decided to remove this feature.
The change is now in the newest egg for zope.security version 3.4.0b2
With this new version we also measured the time with zope as a trunk checkout (no eggs involved).
The publisher is now twice as fast as it was before! newInteraction is called exactly once for each request but was taking 50% of the time (without eggs) for the publisher.
Here’s Jürgens lesson: “I’m writing this just to show everyone what can happen if not enough care is taken in really critical parts inside the zope core.”
——————–
Yay! good job guys.
Questions:
Does someone know why running python code out of eggs is slower (e.g. linecache)? Are there other functions that are slower out of eggs? What can be done against that?
I am proud of you guys! :-)
Re eggs, one thing I do know is that the PYTHONPATH (sys.path) can become *very* long with eggs.
Wow, thanks for tracking this down and fixing it. It’s not often that somebody doubles Zope’s requests per seconds :).
As far as eggs are concerned, I understand that startup can take considerably more time because imports have to walk a much longer sys.path (as lurker already correctly stated). Since you’ve shown that constructing a traceback can take quite some time, I could imagine that passing messages around by raising exceptions and catching them (something that does happen in Zope quite a lot) might be slower.
Just curious: ‘lovely.remotetask throws an IndexError exception if there is no job to do.’ Why this?
it’s polling a queue. if there are no entries in the queue, an index error is beeing raised (and catched at another place). http://svn.zope.org/lovely.remotetask/trunk/src/lovely/remotetask/service.py?rev=76712&r1=76637&r2=76712
Interesting things they do ;)