Bzr 'time' measurement
Will Lentz
Will_Lentz at Trimble.com
Fri Apr 7 19:12:01 BST 2006
Hi,
I'm looking for help on how to debug a bzr 0.7 speed problem on my
redhat machine.
The problem only happens once at the start of each day. The first time
I run something like 'time bzr st' or 'time bzr info' the "real" time is
always much larger than the "user+sys" time. For the rest of the day
the "real" and "user" time are in pretty close agreement. I have
multiple bzr-versioned directories, and the problem happens on each
directory (i.e., running 'bzr info' on 1 directory doesn't speed up
another separate bzr-versioned directory).
I've included some diagnostics from the first 2 runs of the day below.
Any ideas on how to debug this further?
Thanks,
Will
------------------------------------------
1st run:
$ time bzr info --profile
branch format: Bazaar-NG branch, format 6
in the working tree:
4686 unchanged
0 modified
0 added
0 removed
0 renamed
9 unknown
1007 ignored
372 versioned subdirectories
branch history:
79 revisions
1 committer
41 days old
first revision: Fri 2006-02-24 14:35:48 -0800
latest revision: Thu 2006-04-06 16:56:53 -0700
revision store:
79 revisions
37 kB
535382 function calls (534956 primitive calls) in 2.045 CPU
seconds
Ordered by: cumulative time
List reduced from 214 to 20 due to restriction <20>
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.000 0.000 2.045 2.045 commands.py:211(run_argv)
1 0.000 0.000 2.045 2.045
commands.py:544(ignore_pipe)
1 0.016 0.016 2.045 2.045 builtins.py:637(run)
1 0.012 0.012 1.850 1.850 info.py:33(show_info)
1 0.000 0.000 0.897 0.897
delta.py:145(compare_trees)
1 0.090 0.090 0.897 0.897
delta.py:176(_compare_trees)
4399 0.027 0.000 0.582 0.000 branch.py:75(decorated)
3 0.002 0.001 0.537 0.179
workingtree.py:181(__init__)
8626 0.050 0.000 0.499 0.000
inventory.py:568(_read_tree_state)
1016 0.155 0.000 0.406 0.000
workingtree.py:738(is_ignored)
4 0.072 0.018 0.403 0.101
xml5.py:114(_unpack_inventory)
2 0.000 0.000 0.358 0.179
branch.py:1045(working_tree)
3 0.000 0.000 0.300 0.100
workingtree.py:810(read_working_inventory)
3 0.004 0.001 0.300 0.100 xml.py:53(read_inventory)
1 0.007 0.007 0.298 0.298 branch.py:1035(basis_tree)
18744 0.104 0.000 0.297 0.000 xml5.py:133(_unpack_entry)
22686 0.219 0.000 0.279 0.000 inventory.py:997(id2path)
36607 0.091 0.000 0.209 0.000 osutils.py:461(splitpath)
3 0.079 0.026 0.201 0.067 hashcache.py:121(scan)
4313 0.023 0.000 0.192 0.000
workingtree.py:321(get_file_sha1)
real 0m26.349s
user 0m16.100s
sys 0m0.250s
---------------------------------------------------
2nd run:
$ time bzr info --profile
branch format: Bazaar-NG branch, format 6
in the working tree:
4686 unchanged
0 modified
0 added
0 removed
0 renamed
9 unknown
1007 ignored
372 versioned subdirectories
branch history:
79 revisions
1 committer
41 days old
first revision: Fri 2006-02-24 14:35:48 -0800
latest revision: Thu 2006-04-06 16:56:53 -0700
revision store:
79 revisions
37 kB
535382 function calls (534956 primitive calls) in 2.027 CPU
seconds
Ordered by: cumulative time
List reduced from 214 to 20 due to restriction <20>
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.000 0.000 2.027 2.027 commands.py:211(run_argv)
1 0.000 0.000 2.027 2.027
commands.py:544(ignore_pipe)
1 0.017 0.017 2.027 2.027 builtins.py:637(run)
1 0.012 0.012 1.833 1.833 info.py:33(show_info)
1 0.000 0.000 0.891 0.891
delta.py:145(compare_trees)
1 0.088 0.088 0.891 0.891
delta.py:176(_compare_trees)
4399 0.026 0.000 0.574 0.000 branch.py:75(decorated)
3 0.002 0.001 0.531 0.177
workingtree.py:181(__init__)
8626 0.049 0.000 0.493 0.000
inventory.py:568(_read_tree_state)
1016 0.152 0.000 0.404 0.000
workingtree.py:738(is_ignored)
4 0.072 0.018 0.401 0.100
xml5.py:114(_unpack_inventory)
2 0.000 0.000 0.355 0.177
branch.py:1045(working_tree)
3 0.000 0.000 0.298 0.099
workingtree.py:810(read_working_inventory)
3 0.004 0.001 0.298 0.099 xml.py:53(read_inventory)
1 0.007 0.007 0.296 0.296 branch.py:1035(basis_tree)
18744 0.104 0.000 0.295 0.000 xml5.py:133(_unpack_entry)
22686 0.218 0.000 0.278 0.000 inventory.py:997(id2path)
36607 0.091 0.000 0.209 0.000 osutils.py:461(splitpath)
3 0.076 0.025 0.197 0.066 hashcache.py:121(scan)
4313 0.024 0.000 0.190 0.000
workingtree.py:321(get_file_sha1)
real 0m17.761s
user 0m16.270s
sys 0m0.190s
More information about the bazaar
mailing list