1
 
For a tree holding 2.4.18 (two copies), 2.4.19, 2.4.20
 
8
 
12355   .bzr/inventory-store
 
15
 
This is actually a pretty bad example because of deleting and
 
16
 
re-importing 2.4.18, but still not totally unreasonable.
 
20
 
linux-2.4.0: 116399 kB
 
21
 
after addding everything: 119505kB
 
22
 
bzr status  2.68s user 0.13s system 84% cpu 3.330 total
 
23
 
bzr commit 'import 2.4.0'  4.41s user 2.15s system 11% cpu 59.490 total
 
31
 
Performance (2005-03-01)
 
33
 
To add all files from linux-2.4.18: about 70s, mostly inventory
 
34
 
serialization/deserialization.
 
37
 
- finished, 6.520u/3.870s cpu, 33.940u/10.730s cum
 
40
 
Interesting that it spends so long on external processing!  I wonder
 
41
 
if this is for running uuidgen?  Let's try generating things
 
44
 
Great, this cuts it to 17.15s user 0.61s system 83% cpu 21.365 total
 
45
 
to add, with no external command time.  The commit now seems to spend
 
46
 
most of its time copying to disk.
 
48
 
- finished, 6.550u/3.320s cpu, 35.050u/9.870s cum
 
51
 
I wonder where the external time is now?  We were also using uuids()
 
54
 
Let's remove everything and re-add.  Detecting everything was removed
 
56
 
- finished, 2.460u/0.110s cpu, 0.000u/0.000s cum
 
59
 
which may be mostly XML deserialization?
 
61
 
Just getting the previous revision takes about this long:
 
63
 
bzr invoked at Tue 2005-03-01 15:53:05.183741 EST +1100
 
64
 
  by mbp@sourcefrog.net on hope
 
65
 
  arguments: ['/home/mbp/bin/bzr', 'get-revision-inventory', 'mbp@sourcefrog.net-20050301044608-8513202ab179aff4-44e8cd52a41aa705']
 
66
 
  platform: Linux-2.6.10-4-686-i686-with-debian-3.1
 
67
 
- finished, 3.910u/0.390s cpu, 0.000u/0.000s cum
 
70
 
Now committing the revision which removes all files should be fast.
 
72
 
- finished, 1.280u/0.030s cpu, 0.000u/0.000s cum
 
75
 
Now re-add with new code that doesn't call uuidgen:
 
77
 
- finished, 1.990u/0.030s cpu, 0.000u/0.000s cum
 
80
 
16.61s user 0.55s system 74% cpu 22.965 total
 
84
 
  - finished, 2.500u/0.110s cpu, 0.010u/0.000s cum
 
89
 
Now patch up to 2.4.19.  There were some bugs in handling missing
 
90
 
directories, but with that fixed we do much better::
 
92
 
  bzr status  5.86s user 1.06s system 10% cpu 1:05.55 total
 
94
 
This is slow because it's diffing every file; we should use mtimes etc
 
95
 
to make this faster.  The cpu time is reasonable.
 
97
 
I see difflib is pure Python; it might be faster to shell out to GNU
 
100
 
Export is very fast::
 
102
 
  - finished, 4.220u/1.480s cpu, 0.010u/0.000s cum
 
105
 
  bzr export 1 ../linux-2.4.18.export1  3.92s user 1.72s system 21% cpu 26.030 total
 
108
 
Now to find and add the new changes::
 
110
 
  - finished, 2.190u/0.030s cpu, 0.000u/0.000s cum
 
115
 
  bzr commit 'import 2.4.19'  9.36s user 1.91s system 23% cpu 47.127 total
 
117
 
And the result is exactly right.  Try exporting::
 
119
 
  mbp@hope%  bzr export 4 ../linux-2.4.19.export4
 
120
 
  bzr export 4 ../linux-2.4.19.export4  4.21s user 1.70s system 18% cpu 32.304 total
 
122
 
and the export is exactly the same as the tarball.
 
124
 
Now we can optimize the diff a bit more by not comparing files that
 
125
 
have the right SHA-1 from within the commit
 
129
 
  patch -p1 < ../kernel.pkg/patch-2.4.20  1.61s user 1.03s system 13% cpu 19.106 total
 
132
 
Now status after applying the .20 patch.  With full-text verification::
 
134
 
  bzr status  7.07s user 1.32s system 13% cpu 1:04.29 total
 
136
 
with that turned off::
 
138
 
  bzr status  5.86s user 0.56s system 25% cpu 25.577 total
 
142
 
  bzr status  6.14s user 0.61s system 25% cpu 26.583 total
 
144
 
Should add some kind of profile counter for quick compares vs slow
 
147
 
  bzr commit 'import 2.4.20'  7.57s user 1.36s system 20% cpu 43.568
 
150
 
export:  finished, 3.940u/1.820s cpu, 0.000u/0.000s cum,  50.990 elapsed
 
152
 
also exports correctly
 
156
 
bzr commit 'import 2.4.1'  5.59s user 0.51s system 60% cpu 10.122 total
 
166
 
with everything through to 2.4.29 imported, the .bzr directory is
 
167
 
1132MB, compared to 185MB for one tree.  The .bzr.log is 100MB!.  So
 
168
 
the storage is 6.1 times larger, although we're holding 30 versions.
 
169
 
It's pretty large but I think not ridiculous.  By contrast the tarball
 
170
 
for 2.4.0 is 104MB, and the tarball plus uncompressed patches are
 
173
 
Uncompressed, the text store is 1041MB.  So it is only three times
 
174
 
worse than patches, and could be compressed at presumably roughly
 
175
 
equal efficiency.  It is large, but also a very simple design and
 
176
 
perhaps adequate for the moment.  The text store with each file
 
177
 
individually gziped is 264MB, which is also a very simple format and
 
178
 
makes it less than twice the size of the source tree.
 
180
 
This is actually rather pessimistic because I think there are some
 
181
 
orphaned texts in there.
 
183
 
Measured by du, the compressed full-text store is 363MB; also probably
 
186
 
The real fix is perhaps to use some kind of weave, not so much for
 
187
 
storage efficiency as for fast annotation and therefore possible
 
188
 
annotation-based merge.
 
195
 
Now we have recursive add, add is much faster.  Adding all of the
 
196
 
linux 2.4.19 kernel tree takes only 
 
198
 
finished, 5.460u/0.610s cpu, 0.010u/0.000s cum, 6.710 elapsed
 
201
 
However, the store code currently flushes to disk after every write,
 
202
 
which is probably excessive.  So a commit takes
 
204
 
finished, 8.740u/3.950s cpu, 0.010u/0.000s cum, 156.420 elapsed
 
207
 
Status is now also quite fast, depsite that it still has to read all
 
210
 
mbp@hope% bzr status                                                            ~/work/linux-2.4.19
 
211
 
bzr status  5.51s user 0.79s system 99% cpu 6.337 total
 
213
 
strace shows much of this is in write(2), probably because of
 
214
 
logging.  With more buffering on that file, removing all the explicit
 
215
 
flushes, that is reduced to 
 
217
 
mbp@hope% time bzr status  
 
218
 
bzr status  5.23s user 0.42s system 97% cpu 5.780 total
 
220
 
which is mostly opening, stating and reading files, as it should be.
 
221
 
Still a few too many stat calls.
 
223
 
Now fixed up handling of root directory.
 
225
 
Without flushing everything to disk as it goes into the store:
 
227
 
mbp@hope% bzr commit -m 'import linux 2.4.19'
 
228
 
bzr commit -m 'import linux 2.4.19'  8.15s user 2.09s system 53% cpu 19.295 total
 
230
 
mbp@hope% time bzr diff
 
231
 
bzr diff  5.80s user 0.52s system 69% cpu 9.128 total
 
232
 
mbp@hope% time bzr status
 
233
 
bzr status  5.64s user 0.43s system 68% cpu 8.848 total
 
235
 
patch -p1 < ../linux.pkg/patch-2.4.20  1.67s user 0.96s system 90% cpu 2.905 total
 
237
 
The diff changes 3462 files according to diffstat.
 
239
 
branch format: Bazaar-NG branch, format 0.0.4
 
249
 
    614 versioned subdirectories
 
251
 
That is, 3510 entries have changed, but there are 48 changed
 
252
 
directories so the count is exactly right!
 
254
 
bzr commit -v -m 'import 2.4.20'  8.23s user 1.09s system 48% cpu 19.411 total
 
256
 
Kind of strange that this takes as much time as committing the whole
 
257
 
thing; I suppose it has to read every file.  
 
259
 
This shows many files as being renamed; I don't know why that would
 
265
 
 2969 files changed, 366643 insertions(+), 147759 deletions(-)
 
269
 
 2969 files changed, 372168 insertions(+), 153284 deletions(-)
 
271
 
I wonder why it is not exactly the same?  Maybe because the python
 
272
 
diff algorithm is a bit differnt to GNU diff.
 
278
 
full check, retrieving all file texts once for the 2.4 kernel branch
 
279
 
takes 10m elapsed, 1m cpu time.  lots of random IO and seeking.
 
284
 
mbp@hope% time python =bzr deleted --show-ids 
 
285
 
README                                             README-fa1d8447b4fd0140-adbf4342752f0fc3
 
286
 
python =bzr deleted --show-ids  1.55s user 0.09s system 96% cpu 1.701 total
 
287
 
mbp@hope% time python -O =bzr deleted --show-ids 
 
288
 
README                                             README-fa1d8447b4fd0140-adbf4342752f0fc3
 
289
 
python -O =bzr deleted --show-ids  1.47s user 0.10s system 101% cpu 1.547 total
 
290
 
mbp@hope% time python -O =bzr deleted --show-ids
 
291
 
README                                             README-fa1d8447b4fd0140-adbf4342752f0fc3
 
292
 
python -O =bzr deleted --show-ids  1.49s user 0.07s system 99% cpu 1.565 total
 
293
 
mbp@hope% time python =bzr deleted --show-ids   
 
294
 
README                                             README-fa1d8447b4fd0140-adbf4342752f0fc3
 
295
 
python =bzr deleted --show-ids  1.55s user 0.08s system 99% cpu 1.637 total
 
297
 
small but significant improvement from Python -O
 
301
 
Loading a large inventory through cElementTree is pretty quick; only
 
302
 
about 0.117s.  By contrast reading the inventory into our data
 
303
 
structure takes about 0.7s.  
 
305
 
So I think the problem must be in converting everything to
 
306
 
InventoryEntries and back again every time.
 
308
 
Thought about that way it seems pretty inefficient: why create all
 
309
 
those objects when most of them aren't called on most invocations?
 
310
 
Instead perhaps the Inventory object should hold the ElementTree and
 
311
 
pull things out of it only as necessary?  We can even have an index
 
312
 
pointing into the ElementTree by id, path, etc.
 
317
 
bzr deleted  1.46s user 0.08s system 98% cpu 1.561 total
 
320
 
Alternatively maybe keep an id2path and path2id cache?  Keeping it
 
321
 
coherent may be hard...