[Zope-ZEO] Re: ZEO and ZODB timing results
Greg Ward
gward@mems-exchange.org
Wed, 3 May 2000 10:01:47 -0400
On 02 May 2000, Jim Fulton said:
> > Without further ado, here are the timings:
> >
> > task: in-memory ZODB ZEO
> > create users/groups 0.04 0.15 4.90
>
> There's something wrong here. I can't imagine why ZEO
> would be so much slower at this phase, since the storage is
> hardly involved.
Yeah, that jumped out at me too. I've got some more data now, and I'm
even more puzzled: this does *not* appear to be an overhead artifact, as
if I started the timer too early (before initializing the ZEO
connection). With a whopping 2 data points to back me up, it appears
that the overhead scales linearly with problem size.
Details: I re-ran the problem from yesterday (create 20 users and 10
groups) and wrote down more detailed timing: CPU and elapsed times for
ZODB, and CPU and elapsed times for ZEO. Then I did it again for 200
users and 100 groups. Here are the numbers:
ZODB ZEO
cpu elapsed cpu elapsed
20/10 create 0.13 0.15 0.11 4.72
20/10 commit 0.06 0.06 0.02 5.13
200/100 create 1.41 1.53 1.19 50.23
200/100 commit 0.44 0.47 0.22 30.94
Notes:
* all times in seconds; CPU = child + system CPU as returned by
'os.times()', and elapsed time is also from 'os.times()'
* all ZODB timings, and the 20/10 ZEO timings, were averaged across
3 runs; for the 200/100 ZEO run, I was too impatient to run
it 3 times
* however, I did repeat the 200/100 ZEO run after moving the ZEO
database to /tmp on the ZEO server; the results were essentially
the same (49.78 s and 30.65 s elapsed time for create and commit)
Observations:
* CPU time for creation appears to scale linearly with the problem
size, as expected
* create and commit with ZODB are both clearly CPU-bound, as expected
* commit time with ZEO has almost nothing to do with CPU; presumably
it's all network overhead -- as expected
* the oddball: creation time with ZEO scales with the problem size,
but the CPU time is dwarfed (presumably by network overhead), which
just makes no sense at all.
The real oddity is that this does *not* happen with our other object
creation problem (convert the process library). There must be something
peculiar about our User and Group objects that just happens to hammer on
ZEO. These are pretty simple classes, so hopefully the problem will be
traceable! I'll try to get Barry and/or Andrew to help me look into it
at some point today, but I'll also send our code to Jim so he can try to
reproduce some of our whacky numbers -- any maybe figure out what's
going on with user and group creation.
> > * for ZEO "query processes", the bulk of the time was the first query
> > (fill the cache, presumably)
>
> This probably unfairly penalizes ZEO. In a realistic usage scenario,
> most queries will be fed from the local cache.
Until the problem size exceeds the cache size, that is. Since this is a
pretty small database (so far!), I expect the whole thing fits in the
cache. This is demonstrated by looking at more detailed timing for the
"query process library" script. It does 7 queries, all of which involve
walking some portion of the whole object graph. The latter 3 queries
are more detailed and require a deeper graph traversal. Here are
results for a single run with each of ZODB and ZEO:
ZODB ZEO
query: cpu elapsed cpu elapsed
1 0.50 0.52 0.21 14.26
2 0.15 0.15 0.15 0.49
3 0.15 0.15 0.15 0.54
4 0.14 0.14 0.13 0.15
5 0.25 0.25 0.26 2.87
6 0.17 0.17 0.16 0.17
7 0.18 0.18 0.14 1.92
Observations:
* the initial query with ZODB has a bit of a delay as the cache
is filled in; both filling the cache (and the subsequent graph
traversals) appear to be CPU-bound
* the initial cache-fill is *much* more expensive with ZEO, and
clearly not CPU-bound. This is as expected, and not really
a big deal: in a realistic situation, one process would live
for days or weeks and handle many thousands of queries.
* the two queries that involve an extra 2-3 sec delay under ZEO
do so consistently -- this is not a random network effect.
I suspect it might be because these two queries have to go
a bit deeper in the object graph, so there's some more cache-
filling going on here.
* this whole exercise is rather bogus on two accounts: the whole
database (presumably) fits in the client-side cache (which
is an unfair advantage to both ZODB and ZEO), and no indexing of
any kind was done (an unfair disadvantage, unless you're working
for Versant and trying to highlight the fact that Z* don't
do any indexing for you)
I need to re-run this on progressively larger problem sizes, until we
burst the cache and performance on all queries is abysmal. Then I need
to play with indexing schemes.
> Why wouldn't you do the FileStorage and ZEO tests on the same disk?
> You certainly seem to have put FileStorage at an unfair advantage.
I'm now running ZEO with its database on /tmp, and it doesn't seem to
make any difference. (The local disk versus /tmp distinction didn't
really occur to me until I was writing that email yesterday, and I
assumed that since ZEO was most likely network-bound, it wasn't really a
big deal.)
> Wow. These times are really bad. I ran a test that created a 100MB
> database on a crappy old 100Mhz mobile non-MMX pentium-based laptop.
> My time with the ZEO you have was about 2400 seconds. I'd really like to
> get a copy of your test script so I try to understand why your numbers
> are so bad. Obviously, I'd like you to try out a new ZEO as soon as it's
> available.
OK, I'll bundle up our code and send it to Jim. Shhh, don't tell CNRI's
Crack Legal Team(TM) that I'm doing this.
> > Stuff on my immediate agenda:
> > * write that walk-the-database-and-get-some-stats script (or steal
> > someone else's, if it exists)
>
> Why do you want this information?
Mainly curiosity. Also, it seems that number-of-objects is a somewhat
more useful metric of the size of an object database than
number-of-bytes; and once you ask *that* question, it only seems natural
to follow it up with, "Well, how many classes? and how many objects of
each class?"
BTW, I did len() on the DB's _storage attribute; our current (toy
implementation, small problem size) database is around 5000 objects.
> > * try ZODB with a Berkeley DB storage
>
> Cool. What are you hoping to gain?
I'm curious if it would be any faster. My understanding of the file
storage leads me to believe it's about as fast as you're going to get
with pure Python. Also, we have no need for Zope-style "undo", so the
append-only architecture buys us very little, and costs us a
constantly-growing file with the need for periodic packs. All we really
need is a hash file, and Berkely DB should fit the bill nicely.
Greg
--
Greg Ward - software developer gward@mems-exchange.org
MEMS Exchange / CNRI voice: +1-703-262-5376
Reston, Virginia, USA fax: +1-703-262-5367