Re: Locks on the Bzr repository

[Jason Rumney]

 On 20/8/2010 12:24 AM, Eli Zaretskii wrote:
> > From: Stefan Monnier<address@hidden>
> > Date: Thu, 19 Aug 2010 17:40:29 +0200
> >
> > Could it be that bzr grabs the lock when you do "bzr commit" and keep it
> > held for as long as you're editing the commit message?
> Maybe so, but why would it take Jason 28 minutes and 50-odd seconds to
> edit a commit message?
>
> I suspect the culprit is network traffic, but Jason should be able to
> tell more by looking at his .bzr.log file, where each operation is
> logged together with its timing.
Here are the commits I performed today:

The first one went quite smoothly but took about 8 minutes.

Thu 2010-08-19 22:50:16 +0800
0.058  bazaar version: 2.1.1
0.058  bzr arguments: [u'commit', u'-m', u"(w32_wnd_proc): Don't check 
context before initializing.\n", u'src/ChangeLog', u'src/w32fns.c']
0.086  looking for plugins in /home/jasonr/.bazaar/plugins
0.086  looking for plugins in 
/usr/lib/python2.6/dist-packages/bzrlib/plugins
0.159  encoding stdout as osutils.get_user_encoding() 'UTF-8'
0.225  opening working tree '/home/jasonr/bzr/emacs/trunk'
0.303  ssh implementation is OpenSSH
28.204  preparing to commit
[22809] 2010-08-19 22:51:09.255 INFO: Committing to: 
sftp://address@hidden/srv/bzr/emacs/trunk/
52.688  Selecting files for commit with filter [u'src/ChangeLog', 
u'src/w32fns.c']
[22809] 2010-08-19 22:51:09.326 INFO: modified src/ChangeLog
[22809] 2010-08-19 22:51:09.344 INFO: modified src/w32fns.c
52.990  Using fetch logic to copy between 
CHKInventoryRepository('file:///home/jasonr/bzr/emacs/.bzr/repository/')(RepositoryFormat2a()) 
and 
CHKInventoryRepository('sftp://address@hidden/srv/bzr/emacs/.bzr/repository/')(RepositoryFormat2a())
52.990  fetch up to rev address@hidden
[22809] 2010-08-19 22:58:21.431 INFO: Committed revision 101137.
487.501  return code 0


The second attempt failed, perhaps due to Stefan breaking the lock (as 
it failed in unlock self.confirm):
Thu 2010-08-19 23:07:28 +0800
0.052  bazaar version: 2.1.1
0.053  bzr arguments: [u'commit', u'-m', u'(set_frame_menubar): Remove 
call to undefined function.\n', u'src/ChangeLog', u'src/w32menu.c']
0.084  looking for plugins in /home/jasonr/.bazaar/plugins
0.085  looking for plugins in 
/usr/lib/python2.6/dist-packages/bzrlib/plugins
0.246  encoding stdout as osutils.get_user_encoding() 'UTF-8'
0.301  opening working tree '/home/jasonr/bzr/emacs/trunk'
0.606  ssh implementation is OpenSSH
29.123  preparing to commit
[23356] 2010-08-19 23:08:28.093 INFO: Committing to: 
sftp://address@hidden/srv/bzr/emacs/trunk/
59.322  Selecting files for commit with filter [u'src/ChangeLog', 
u'src/w32menu.c']
[23356] 2010-08-19 23:08:28.202 INFO: modified src/ChangeLog
[23356] 2010-08-19 23:08:28.225 INFO: modified src/w32menu.c
59.631  Using fetch logic to copy between 
CHKInventoryRepository('file:///home/jasonr/bzr/emacs/.bzr/repository/')(RepositoryFormat2a()) 
and 
CHKInventoryRepository('sftp://address@hidden/srv/bzr/emacs/.bzr/repository/')(RepositoryFormat2a())
59.631  fetch up to rev address@hidden
470.146  Raising exception with args ('Server connection dropped: ',)
470.146  Error suppressed by only_raises:
470.164  Traceback (most recent call last):
  File "/usr/lib/python2.6/dist-packages/bzrlib/decorators.py", line 
222, in wrapped
    return unbound(*args, **kwargs)
  File "/usr/lib/python2.6/dist-packages/bzrlib/lockdir.py", line 319, 
in unlock
    self.confirm()
  File "/usr/lib/python2.6/dist-packages/bzrlib/lockdir.py", line 415, 
in confirm
    info = self.peek()
  File "/usr/lib/python2.6/dist-packages/bzrlib/lockdir.py", line 438, 
in peek
    info = self._read_info_file(self._held_info_path)
  File "/usr/lib/python2.6/dist-packages/bzrlib/lockdir.py", line 428, 
in _read_info_file
    return self._parse_info(self.transport.get_bytes(path))
  File "/usr/lib/python2.6/dist-packages/bzrlib/transport/sftp.py", 
line 435, in get_bytes
    f = self.get(relpath)
  File "/usr/lib/python2.6/dist-packages/bzrlib/transport/sftp.py", 
line 431, in get
    failure_exc=errors.ReadError)
  File "/usr/lib/python2.6/dist-packages/bzrlib/transport/sftp.py", 
line 721, in _translate_io_exception
    raise e
SSHException: Server connection dropped:

470.167  Error suppressed by only_raises:
470.208  Traceback (most recent call last):
  File "/usr/lib/python2.6/dist-packages/bzrlib/decorators.py", line 
222, in wrapped
    return unbound(*args, **kwargs)
  File "/usr/lib/python2.6/dist-packages/bzrlib/lockdir.py", line 319, 
in unlock
    self.confirm()
  File "/usr/lib/python2.6/dist-packages/bzrlib/lockdir.py", line 415, 
in confirm
    info = self.peek()
  File "/usr/lib/python2.6/dist-packages/bzrlib/lockdir.py", line 438, 
in peek
    info = self._read_info_file(self._held_info_path)
  File "/usr/lib/python2.6/dist-packages/bzrlib/lockdir.py", line 428, 
in _read_info_file
    return self._parse_info(self.transport.get_bytes(path))
  File "/usr/lib/python2.6/dist-packages/bzrlib/transport/sftp.py", 
line 435, in get_bytes
    f = self.get(relpath)
  File "/usr/lib/python2.6/dist-packages/bzrlib/transport/sftp.py", 
line 425, in get
    f = self._get_sftp().file(path, mode='rb')
  File "/usr/lib/pymodules/python2.6/paramiko/sftp_client.py", line 
245, in open
    t, msg = self._request(CMD_OPEN, filename, imode, attrblock)
  File "/usr/lib/pymodules/python2.6/paramiko/sftp_client.py", line 
627, in _request
    num = self._async_request(type(None), t, *arg)
  File "/usr/lib/pymodules/python2.6/paramiko/sftp_client.py", line 
649, in _async_request
    self._send_packet(t, str(msg))
  File "/usr/lib/pymodules/python2.6/paramiko/sftp.py", line 172, in 
_send_packet
    self._write_all(out)
  File "/usr/lib/pymodules/python2.6/paramiko/sftp.py", line 136, in 
_write_all
    n = self.sock.send(out)
  File "/usr/lib/python2.6/dist-packages/bzrlib/transport/ssh.py", line 
194, in send
    return self.__socket.send(data)
  File "/usr/lib/python2.6/dist-packages/bzrlib/transport/ssh.py", line 
665, in send
    return os.write(self.proc.stdin.fileno(), data)
OSError: [Errno 32] Broken pipe

470.313  Traceback (most recent call last):
  File "/usr/lib/python2.6/dist-packages/bzrlib/commands.py", line 853, 
in exception_to_return_code
    return the_callable(*args, **kwargs)
  File "/usr/lib/python2.6/dist-packages/bzrlib/commands.py", line 
1055, in run_bzr
    ret = run(*run_argv)
  File "/usr/lib/python2.6/dist-packages/bzrlib/commands.py", line 661, 
in run_argv_aliases
    return self.run_direct(**all_cmd_args)
  File "/usr/lib/python2.6/dist-packages/bzrlib/commands.py", line 665, 
in run_direct
    return self._operation.run_simple(*args, **kwargs)
  File "/usr/lib/python2.6/dist-packages/bzrlib/cleanup.py", line 122, 
in run_simple
    self.cleanups, self.func, *args, **kwargs)
  File "/usr/lib/python2.6/dist-packages/bzrlib/cleanup.py", line 156, 
in _do_with_cleanups
    result = func(*args, **kwargs)
  File "/usr/lib/python2.6/dist-packages/bzrlib/builtins.py", line 
3138, in run
    exclude=safe_relpath_files(tree, exclude))
  File "/usr/lib/python2.6/dist-packages/bzrlib/decorators.py", line 
194, in write_locked
    result = unbound(self, *args, **kwargs)
  File "/usr/lib/python2.6/dist-packages/bzrlib/workingtree_4.py", line 
197, in commit
    result = WorkingTree3.commit(self, message, revprops, *args, **kwargs)
  File "/usr/lib/python2.6/dist-packages/bzrlib/decorators.py", line 
194, in write_locked
    result = unbound(self, *args, **kwargs)
  File "/usr/lib/python2.6/dist-packages/bzrlib/mutabletree.py", line 
225, in commit
    *args, **kwargs)
  File "/usr/lib/python2.6/dist-packages/bzrlib/commit.py", line 257, 
in commit
    possible_master_transports=possible_master_transports)
  File "/usr/lib/python2.6/dist-packages/bzrlib/cleanup.py", line 118, 
in run
    self.cleanups, self.func, self, *args, **kwargs)
  File "/usr/lib/python2.6/dist-packages/bzrlib/cleanup.py", line 156, 
in _do_with_cleanups
    result = func(*args, **kwargs)
  File "/usr/lib/python2.6/dist-packages/bzrlib/commit.py", line 420, 
in _commit
    self.branch.repository, new_revno, self.rev_id)
  File "/usr/lib/python2.6/dist-packages/bzrlib/branch.py", line 924, 
in import_last_revision_info
    self.set_last_revision_info(revno, revid)
  File "/usr/lib/python2.6/dist-packages/bzrlib/decorators.py", line 
194, in write_locked
    result = unbound(self, *args, **kwargs)
  File "/usr/lib/python2.6/dist-packages/bzrlib/branch.py", line 2508, 
in set_last_revision_info
    if self._get_append_revisions_only():
  File "/usr/lib/python2.6/dist-packages/bzrlib/branch.py", line 2691, 
in _get_append_revisions_only
    value = self.get_config().get_user_option('append_revisions_only')
  File "/usr/lib/python2.6/dist-packages/bzrlib/config.py", line 187, 
in get_user_option
    return self._get_user_option(option_name)
  File "/usr/lib/python2.6/dist-packages/bzrlib/config.py", line 733, 
in _get_user_option
    value = source()._get_user_option(option_name)
  File "/usr/lib/python2.6/dist-packages/bzrlib/config.py", line 406, 
in _get_user_option
    value = self._get_parser().get_value(section, option_name)
  File "/usr/lib/python2.6/dist-packages/bzrlib/config.py", line 997, 
in _get_parser
    return self._config._get_configobj()
  File "/usr/lib/python2.6/dist-packages/bzrlib/config.py", line 1505, 
in _get_configobj
    return ConfigObj(self._get_config_file(), encoding='utf-8')
  File "/usr/lib/python2.6/dist-packages/bzrlib/config.py", line 1500, 
in _get_config_file
    return StringIO(self._transport.get_bytes(self._filename))
  File "/usr/lib/python2.6/dist-packages/bzrlib/transport/sftp.py", 
line 435, in get_bytes
    f = self.get(relpath)
  File "/usr/lib/python2.6/dist-packages/bzrlib/transport/sftp.py", 
line 425, in get
    f = self._get_sftp().file(path, mode='rb')
  File "/usr/lib/pymodules/python2.6/paramiko/sftp_client.py", line 
245, in open
    t, msg = self._request(CMD_OPEN, filename, imode, attrblock)
  File "/usr/lib/pymodules/python2.6/paramiko/sftp_client.py", line 
627, in _request
    num = self._async_request(type(None), t, *arg)
  File "/usr/lib/pymodules/python2.6/paramiko/sftp_client.py", line 
649, in _async_request
    self._send_packet(t, str(msg))
  File "/usr/lib/pymodules/python2.6/paramiko/sftp.py", line 172, in 
_send_packet
    self._write_all(out)
  File "/usr/lib/pymodules/python2.6/paramiko/sftp.py", line 136, in 
_write_all
    n = self.sock.send(out)
  File "/usr/lib/python2.6/dist-packages/bzrlib/transport/ssh.py", line 
194, in send
    return self.__socket.send(data)
  File "/usr/lib/python2.6/dist-packages/bzrlib/transport/ssh.py", line 
665, in send
    return os.write(self.proc.stdin.fileno(), data)
OSError: [Errno 32] Broken pipe

470.314  return code 3

By the time I'd tried again and failed due to my own stale locks (I'm 
not sure why - did bzr revive them after the above failure?), and then 
an out of date tree; updated the tree with Stefan's changes; and  
finally committed successfully, it had taken me 50 minutes to commit a 2 
line change!