Cherrypick merge from stacked bzr+ssh makes far too many HPSS calls

[Andrew Bennetts]

I just attempted this command:

$ bzr merge lp:~gz/bzr/escape_selftest_console_output_633216 -r 5411..

I killed it after nearly 10 minutes, 1332 HPSS calls (17 vfs), and only 1031kB of transfer (~1.9 kB/s).

Quick guess: resolving that revision range in a stacked repository is causing bzr to walk history 1 rev at a time in the stacked repo.

Here's the traceback when I interrupted it:

Traceback (most recent call last):
  File "/home/andrew/code/bzr/bzrlib/commands.py", line 912, in exception_to_return_code
    return the_callable(*args, **kwargs)
  File "/home/andrew/code/bzr/bzrlib/commands.py", line 1112, in run_bzr
    ret = run(*run_argv)
  File "/home/andrew/code/bzr/bzrlib/commands.py", line 690, in run_argv_aliases
    return self.run(**all_cmd_args)
  File "/home/andrew/code/bzr/bzrlib/commands.py", line 705, in run
    return self._operation.run_simple(*args, **kwargs)
  File "/home/andrew/code/bzr/bzrlib/cleanup.py", line 135, in run_simple
    self.cleanups, self.func, *args, **kwargs)
  File "/home/andrew/code/bzr/bzrlib/cleanup.py", line 165, in _do_with_cleanups
    result = func(*args, **kwargs)
  File "/home/andrew/code/bzr/bzrlib/builtins.py", line 3846, in run
    location, revision, remember, possible_transports, None)
  File "/home/andrew/code/bzr/bzrlib/builtins.py", line 3965, in _get_merger_from_branch
    other_revision_id = revision[-1].as_revision_id(other_branch)
  File "/home/andrew/code/bzr/bzrlib/revisionspec.py", line 240, in as_revision_id
    return self._as_revision_id(context_branch)
  File "/home/andrew/code/bzr/bzrlib/revisionspec.py", line 248, in _as_revision_id
    return self.in_history(context_branch).rev_id
  File "/home/andrew/code/bzr/bzrlib/revisionspec.py", line 215, in in_history
    revs = branch.revision_history()
  File "/home/andrew/code/bzr/bzrlib/remote.py", line 2791, in revision_history
    return self._real_branch.revision_history()
  File "/home/andrew/code/bzr/bzrlib/decorators.py", line 140, in read_locked
    result = unbound(self, *args, **kwargs)
  File "/home/andrew/code/bzr/bzrlib/branch.py", line 944, in revision_history
    history = self._gen_revision_history()
  File "/home/andrew/code/bzr/bzrlib/branch.py", line 2853, in _gen_revision_history
    self._extend_partial_history(stop_index=last_revno-1)
  File "/home/andrew/code/bzr/bzrlib/branch.py", line 148, in _extend_partial_history
    stop_index=stop_index, stop_revision=stop_revision)
  File "/home/andrew/code/bzr/bzrlib/repository.py", line 4739, in _iter_for_revno
    revision_id = iterator.next()
  File "/home/andrew/code/bzr/bzrlib/remote.py", line 1715, in iter_reverse_revision_history
    parents = graph.get_parent_map([next_id])[next_id]
  File "/home/andrew/code/bzr/bzrlib/graph.py", line 99, in get_parent_map
    new_found = parents_provider.get_parent_map(remaining)
  File "/home/andrew/code/bzr/bzrlib/graph.py", line 167, in get_parent_map
    parent_map = self._get_parent_map(needed_revisions)
  File "/home/andrew/code/bzr/bzrlib/remote.py", line 1503, in _get_parent_map_rpc
    verb, args, body)
  File "/home/andrew/code/bzr/bzrlib/remote.py", line 76, in _call_with_body_bytes_expecting_body
    method, args, body_bytes)
  File "/home/andrew/code/bzr/bzrlib/smart/client.py", line 170, in call_with_body_bytes_expecting_body
    method, args, body=body, expect_response_body=True)
  File "/home/andrew/code/bzr/bzrlib/smart/client.py", line 81, in _call_and_read_response
    expect_body=expect_response_body),
  File "/home/andrew/code/bzr/bzrlib/smart/message.py", line 299, in read_response_tuple
    self._wait_for_response_args()
  File "/home/andrew/code/bzr/bzrlib/smart/message.py", line 264, in _wait_for_response_args
    self._read_more()
  File "/home/andrew/code/bzr/bzrlib/smart/message.py", line 277, in _read_more
    bytes = self._medium_request.read_bytes(next_read_size)
  File "/home/andrew/code/bzr/bzrlib/smart/medium.py", line 462, in read_bytes
    return self._read_bytes(count)
  File "/home/andrew/code/bzr/bzrlib/smart/medium.py", line 474, in _read_bytes
    return self._medium.read_bytes(count)
  File "/home/andrew/code/bzr/bzrlib/smart/medium.py", line 149, in read_bytes
    return self._read_bytes(bytes_to_read)
  File "/home/andrew/code/bzr/bzrlib/smart/medium.py", line 840, in _read_bytes
    return self._real_medium.read_bytes(count)
  File "/home/andrew/code/bzr/bzrlib/smart/medium.py", line 149, in read_bytes
    return self._read_bytes(bytes_to_read)
  File "/home/andrew/code/bzr/bzrlib/smart/medium.py", line 881, in _read_bytes
    self._socket, self._report_activity)
  File "/home/andrew/code/bzr/bzrlib/osutils.py", line 2006, in read_bytes_from_socket
    bytes = sock.recv(max_read_size)
  File "/home/andrew/code/bzr/bzrlib/breakin.py", line 41, in _debug
    signal.signal(_breakin_signal_number, _debug)
  File "/home/andrew/code/bzr/bzrlib/breakin.py", line 41, in _debug
    signal.signal(_breakin_signal_number, _debug)
  File "/usr/lib/python2.6/bdb.py", line 46, in trace_dispatch
    return self.dispatch_line(frame)
  File "/usr/lib/python2.6/bdb.py", line 65, in dispatch_line
    if self.quitting: raise BdbQuit

Here's some .bzr.log:

21.918 hpss call: 'get', '/~gz/bzr/escape_selftest_console_output_633216/.bzr/branch/last-revision'
21.918 (to bzr+ssh://bazaar.launchpad.net/~gz/bzr/escape_selftest_console_output_633216/)
22.270 result: ('ok',)
22.270 59 body bytes read
22.271 hpss call w/body: 'Repository.get_parent_map', '~gz/bzr/escape_selftest_console_output_633216/', 'include-missing:', '<email address hidden>' ('\n\n0'...)
22.271 3 bytes
22.649 result: ('ok',)
22.649 206 body bytes read
22.649 hpss call w/body: 'Repository.get_parent_map', '~bzr-pqm/bzr/bzr.dev/', 'include-missing:', '<email address hidden>' ('\n\n0'...)
22.649 3 bytes
23.636 result: ('ok',)
24.391 59506 body bytes read
24.419 hpss call w/body: 'Repository.get_parent_map', '~gz/bzr/escape_selftest_console_output_633216/', 'include-missing:', '<email address hidden>' ('<email address hidden>'...)
24.419 56 bytes
24.776 result: ('ok',)
24.776 92 body bytes read
24.776 hpss call w/body: 'Repository.get_parent_map', '~gz/bzr/escape_selftest_console_output_633216/', 'include-missing:', '<email address hidden>' ('<email address hidden>'...)
24.776 56 bytes
25.134 result: ('ok',)
25.134 92 body bytes read
...
550.532 hpss call w/body: 'Repository.get_parent_map', '~gz/bzr/escape_selftest_console_output_633216/', 'include-missing:', '<email address hidden>'
 ('<email address hidden>'...)
550.532 56 bytes
550.920 result: ('ok',)
550.920 95 body bytes read
550.921 hpss call w/body: 'Repository.get_parent_map', '~gz/bzr/escape_selftest_console_output_633216/', 'include-missing:', '<email address hidden>'
 ('<email address hidden>'...)
550.921 56 bytes
551.295 result: ('ok',)
551.295 94 body bytes read
551.296 hpss call w/body: 'Repository.get_parent_map', '~gz/bzr/escape_selftest_console_output_633216/', 'include-missing:', '<email address hidden>'
 ('<email address hidden>'...)
551.296 56 bytes

[Andrew Bennetts (spiv)]

I should perhaps add that I was trying to cherrypick that branch from lp:bzr into a branch from lp:bzr/2.2.