compressed weaves, and revision.weave
John A Meinel
john at arbash-meinel.com
Fri Oct 28 05:32:41 BST 2005
Michael Ellerman wrote:
> On Fri, 28 Oct 2005 11:33, John A Meinel wrote:
>> Michael Ellerman wrote:
>>> On Thu, 27 Oct 2005 17:00, Michael Ellerman wrote:
>>>> A whole lot of useless junk
>>>> ...
>>>> Actually it doesn't look so bad when you run it a few times, I've got a
>>>> fair amount of RAM so I'm probably caching the whole tree.
>>> Ooops. Those numbers yesterday were on a format 7 branch, but not
>>> compressed, so they're all bogus. I'll try and get some compressed
>>> numbers today sometime.
>> Thanks.
>> I would be curious to compare format 6 versus 7 compressed and
>> uncompressed.
>
> OK, well the numbers from yesterday are valid then, the cbzr numbers are all
> format 7 uncompressed.
>
> Numbers for format 7 compressed:
>
> concordia ~/src/work/ckexec$ time $cbzr st
> real 6m40.589s <-------- WOW
> user 0m23.455s
> sys 0m4.864s
The first time you run "status" or some of the other commands, bzr
updates the .bzr/stat-cache file.
This file indexes files based on their path, and keeps their sha1 hash,
linked to their stat result.
Which means the first time you run "bzr status", it has to compute the
sha1 has of *every* file.
Once you have done it once, then it only has to compute the sha1 hash
for files whose stat has changed.
Also, because it is reading every file, you have to deal with hard-drive
transfer rate, etc.
You are computing the sha1 has of 200+MB for a kernel tree. And we
probably aren't doing it in the most optimal order.
> concordia ~/src/work/ckexec$ time $cbzr st
> real 0m18.522s
> user 0m12.267s
> sys 0m1.638s
> concordia ~/src/work/ckexec$ time $cbzr st
> real 0m14.640s
> user 0m12.152s
> sys 0m1.528s
> concordia ~/src/work/ckexec$ time $cbzr st
> real 0m15.350s
> user 0m12.034s
> sys 0m1.564s
>
> concordia ~/src/work/ckexec$ time $cbzr --profile st
> modified:
> arch/powerpc/kernel/prom.c
> arch/powerpc/kernel/setup_64.c
> arch/powerpc/mm/lmb.c
> patches/ftr_early_param-earlier
> unknown:
> .bzr.backup
> .shelf
> ftr_vpa-unregister
> test.py
> 1589353 function calls (1535865 primitive calls) in 14.876 CPU seconds
>
> Ordered by: cumulative time
> List reduced from 228 to 20 due to restriction <20>
>
> ncalls tottime percall cumtime percall filename:lineno(function)
> 1 0.000 0.000 14.876 14.876 commands.py:193(run_argv)
> 1 0.000 0.000 14.876 14.876 commands.py:501(ignore_pipe)
> 1 0.037 0.037 14.876 14.876 builtins.py:87(run)
> 1 0.000 0.000 14.838 14.838 status.py:24(show_status)
> 1 0.834 0.834 6.677 6.677 delta.py:138(compare_trees)
> 37096 0.474 0.000 4.017 0.000 inventory.py:553(_read_tree_state)
> 1 0.000 0.000 3.775 3.775 branch.py:1020(basis_tree)
> 1 0.000 0.000 3.775 3.775 branch.py:996(revision_tree)
> 1 0.000 0.000 3.775 3.775 branch.py:853(get_revision_inventory)
> 1 0.000 0.000 3.774 3.774 branch.py:834(get_inventory)
This looks like it is taking 3.7s just to extract the inventory from the
weave. And considering that in the other tree this took 1.3s, it is
probably taking 2s just to uncompress the inventory.weave file.
> 2 0.002 0.001 3.313 1.656 status.py:102(list_paths)
> 1 0.139 0.139 2.781 2.781 workingtree.py:322(iter_conflicts)
> 1 0.000 0.000 2.642 2.642 branch.py:839(get_inventory_xml)
> 19716 0.130 0.000 2.569 0.000 workingtree.py:324(<generator expression>)
> 19716 0.125 0.000 2.439 0.000 workingtree.py:243(list_files)
> 1 0.000 0.000 2.346 2.346 branch.py:830(get_inventory_weave)
> 1 0.000 0.000 2.346 2.346 weave.py:102(get_weave)
> 1 0.000 0.000 2.346 2.346 weavefile.py:95(read_weave)
> 1 0.200 0.200 2.346 2.346 weavefile.py:99(read_weave_v5)
> 72016/19716 0.933 0.000 2.314 0.000 workingtree.py:255(descend)
>
I think this is also showing up here, where it is spending 2.3s just in
"read_weave_v5".
>
>
> real 1m19.525s
> user 0m49.085s
> sys 0m24.206s
>
What surprises me a little bit, is that the "compare_trees" times are a
little bit different. Format 6 was 5.7 seconds, while format 7 is
6.5-6.9 seconds.
One obvious place that we are doing extra work is in status.py list_paths().
It looks like we have 2 generators (new.iter_conflicts() and
new.unknowns()).
Probably both of these go through the entire inventory, looking for a
file which is either conflicted or unknown.
On an inventory as large as yours, that is an extra 1.5s.
This probably could be avoided with a combined call, which returns the
status of the file (conflicted or unknown), which can be turned into a
list, and printed out later.
I'm a little surprised to see hashcache.get_file_sha1() be so expensive,
since it should just be a stat + table lookup. Though I guess 18k stat
calls could probably cost 0.8s.
>> Also, if you could just do a "wc -l" against the inventory.weave
>> (naturally you would need to uncompress the compressed format 7).
>
> Format 7:
> concordia ~/src/work/ckexec$ zcat .bzr/inventory.weave.gz | wc -l
> 46050
>
> Format 6:
> concordia ~/src/work/ckexec$ wc -l ../kexec/.bzr/inventory.weave
> 24990 ../kexec/.bzr/inventory.weave
>
>> I'm curious if what you are seeing is because the inventory.weave file
>> simply has almost 2x the lines in it.
>
> Could be, it's pretty close to 2x.
So I'm guessing that long term, format 7 would stay a little slower than
format 6, but it shouldn't get worse.
>
>> Thanks for your performance testing. Is there somewhere that you could
>> put the inventory.weave(.gz) file? I was thinking to test python's gzip
>> versus native gzip for a large, real-life file.
>
> No wozzers.
>
> Weave is at:
> http://michael.ellerman.id.au/files/inventory.weave.gz
Thanks,
John
=:->
>
> cheers
>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 249 bytes
Desc: OpenPGP digital signature
Url : https://lists.ubuntu.com/archives/bazaar/attachments/20051027/74a23eb1/attachment.pgp
More information about the bazaar
mailing list