Bazaar

initial bzr status slow

Asked by Daniel Kończyk

Is it normal for initial (after-boot) command to take a few seconds? Here's the example - when I first run e.g. "bzr status" in my working copy, it takes ~ 4 seconds for processing. Every next call is OK, but this first one seems a bit long for rather small project. I noticed similar behavior in every other project I have here.

some info from one branch (everything is on local host):

dpkg -s bzr
Version: 1.9-1~bazaar1~intrepid1

bzr revno
619

bzr --profile status:
[...]
8717 function calls (8632 primitive calls) in 3.241 CPU seconds

Ordered by: cumulative time
List reduced from 655 to 20 due to restriction <20>

   ncalls tottime percall cumtime percall filename:lineno(function)
        1 0.000 0.000 3.241 3.241 commands.py:506(run_argv_aliases)
        1 0.000 0.000 3.239 3.239 commands.py:851(ignore_pipe)
        1 0.000 0.000 3.239 3.239 builtins.py:195(run)
        1 0.000 0.000 3.100 3.100 status.py:37(show_tree_status)
    68/64 0.001 0.000 3.022 0.047 <string>:1(<module>)
        1 0.000 0.000 2.990 2.990 tree.py:64(changes_from)
        1 0.000 0.000 2.989 2.989 tree.py:774(compare)
        1 0.020 0.020 2.989 2.989 delta.py:206(_compare_trees)
       59 2.940 0.050 2.940 0.050 osutils.py:1264(_walkdirs_utf8)
        1 0.000 0.000 0.133 0.133 builtins.py:62(tree_files)
        1 0.000 0.000 0.133 0.133 builtins.py:89(internal_tree_files)
        1 0.000 0.000 0.117 0.117 workingtree.py:310(open_containing)
       12 0.082 0.007 0.084 0.007 local.py:153(get)
        1 0.000 0.000 0.077 0.077 bzrdir.py:1571(open_workingtree)
        1 0.000 0.000 0.068 0.068 workingtree.py:2908(open)
        1 0.000 0.000 0.068 0.068 workingtree_4.py:1416(_open)
      2/1 0.000 0.000 0.065 0.065 bzrdir.py:1558(open_branch)
        1 0.000 0.000 0.054 0.054 branch.py:1433(open)
      9/8 0.000 0.000 0.051 0.006 lazy_import.py:120(__call__)
       13 0.000 0.000 0.046 0.004 workingtree_4.py:1151(unlock)

Looks like _walkdirs_utf8 takes most of this time
thanks

Question information

Language:
English Edit question
Status:
Solved
For:
Bazaar Edit question
Assignee:
No assignee Edit question
Solved by:
Martin Pool
Solved:
Last query:
Last reply:
Revision history for this message
Best Martin Pool (mbp) said : 		#1

I think this is normal because immediately after booting, neither Python nor the bzr libraries nor the source tree is in memory, and so they need to be brought in. Obviously this is not ideal and we will in future look in to reducing the IO we do to get started.

Revision history for this message
Daniel Kończyk (drmartens) said : 		#2

I actually run those commands above after some work on a different source tree, so python and bzr libs should have been in the memory. I guess then, that it was the new source tree being moved into memory that took the time, as you point out.
OK, but my question was answered, thanks!

Revision history for this message
Daniel Kończyk (drmartens) said : 		#3

Thanks Martin Pool, that solved my question.

Revision history for this message
Daniel Kończyk (drmartens) said : 		#4

BTW, the very first 'bzr status' after boot takes much longer (run on the smaller tree than the previous one):

         7850 function calls (7765 primitive calls) in 7.857 CPU seconds

   Ordered by: cumulative time
   List reduced from 656 to 20 due to restriction <20>

   ncalls tottime percall cumtime percall filename:lineno(function)
        1 0.000 0.000 7.857 7.857 commands.py:506(run_argv_aliases)
        1 0.000 0.000 7.852 7.852 commands.py:851(ignore_pipe)
        1 0.001 0.001 7.852 7.852 builtins.py:195(run)
        1 0.000 0.000 7.437 7.437 status.py:37(show_tree_status)
    68/64 0.001 0.000 7.331 0.115 <string>:1(<module>)
        1 0.000 0.000 7.301 7.301 tree.py:64(changes_from)
        1 0.000 0.000 7.279 7.279 tree.py:774(compare)
        1 0.018 0.018 7.279 7.279 delta.py:206(_compare_trees)
       60 7.223 0.120 7.223 0.120 osutils.py:1264(_walkdirs_utf8)
        1 0.000 0.000 0.377 0.377 builtins.py:62(tree_files)
        1 0.000 0.000 0.377 0.377 builtins.py:89(internal_tree_files)
        1 0.000 0.000 0.320 0.320 workingtree.py:310(open_containing)
        1 0.000 0.000 0.245 0.245 bzrdir.py:1571(open_workingtree)
    40/34 0.000 0.000 0.243 0.007 lazy_import.py:73(_replace)
    40/34 0.068 0.002 0.242 0.007 lazy_import.py:186(_import)
        1 0.000 0.000 0.237 0.237 workingtree.py:2908(open)
        1 0.000 0.000 0.236 0.236 workingtree_4.py:1416(_open)
      2/1 0.000 0.000 0.206 0.206 bzrdir.py:1558(open_branch)
        1 0.000 0.000 0.184 0.184 branch.py:1433(open)
      9/8 0.000 0.000 0.167 0.021 lazy_import.py:120(__call__)