Can no longer push ('error', '')

[treaves]

I just tried to push, and it failed. I've tried this from two different Mac's (server is Ubuntu). This had been working fine until today. And no, there were no server changes. :)

Run command: bzr push
Using saved push location: bzr+ssh://xxx.com/opt/bzr/XXX/trunk/
bzr: ERROR: bzrlib.errors.ErrorFromSmartServer: Error received from smart server: ('error', '')

Traceback (most recent call last):
  File "/Library/Python/2.6/site-packages/bzrlib/commands.py", line 923, in exception_to_return_code
    return the_callable(*args, **kwargs)
  File "/Library/Python/2.6/site-packages/bzrlib/commands.py", line 1123, in run_bzr
    ret = run(*run_argv)
  File "/Library/Python/2.6/site-packages/bzrlib/commands.py", line 691, in run_argv_aliases
    return self.run(**all_cmd_args)
  File "/Library/Python/2.6/site-packages/bzrlib/commands.py", line 710, in run
    return self._operation.run_simple(*args, **kwargs)
  File "/Library/Python/2.6/site-packages/bzrlib/cleanup.py", line 135, in run_simple
    self.cleanups, self.func, *args, **kwargs)
  File "/Library/Python/2.6/site-packages/bzrlib/cleanup.py", line 165, in _do_with_cleanups
    result = func(*args, **kwargs)
  File "/Library/Python/2.6/site-packages/bzrlib/plugins/qbzr/lib/commands.py", line 783, in run
    return run_subprocess_command(cmd, bencoded)
  File "/Library/Python/2.6/site-packages/bzrlib/plugins/qbzr/lib/subprocess.py", line 888, in run_subprocess_command
    return commands.run_bzr(argv)
  File "/Library/Python/2.6/site-packages/bzrlib/commands.py", line 1123, in run_bzr
    ret = run(*run_argv)
  File "/Library/Python/2.6/site-packages/bzrlib/commands.py", line 691, in run_argv_aliases
    return self.run(**all_cmd_args)
  File "/Library/Python/2.6/site-packages/bzrlib/commands.py", line 710, in run
    return self._operation.run_simple(*args, **kwargs)
  File "/Library/Python/2.6/site-packages/bzrlib/cleanup.py", line 135, in run_simple
    self.cleanups, self.func, *args, **kwargs)
  File "/Library/Python/2.6/site-packages/bzrlib/cleanup.py", line 165, in _do_with_cleanups
    result = func(*args, **kwargs)
  File "/Library/Python/2.6/site-packages/bzrlib/builtins.py", line 1134, in run
    use_existing_dir=use_existing_dir, no_tree=no_tree)
  File "/Library/Python/2.6/site-packages/bzrlib/push.py", line 140, in _show_push_branch
    remember, create_prefix)
  File "/Library/Python/2.6/site-packages/bzrlib/controldir.py", line 507, in push_branch
    overwrite, stop_revision=revision_id)
  File "/Library/Python/2.6/site-packages/bzrlib/branch.py", line 1087, in push
    *args, **kwargs)
  File "/Library/Python/2.6/site-packages/bzrlib/branch.py", line 3468, in push
    _override_hook_source_branch=_override_hook_source_branch)
  File "/Library/Python/2.6/site-packages/bzrlib/branch.py", line 3264, in _run_with_write_locked_target
    result = callable(*args, **kwargs)
  File "/Library/Python/2.6/site-packages/bzrlib/branch.py", line 3507, in _push_with_bound_branches
    stop_revision)
  File "/Library/Python/2.6/site-packages/bzrlib/branch.py", line 2654, in _basic_push
    overwrite=overwrite, graph=graph)
  File "/Library/Python/2.6/site-packages/bzrlib/branch.py", line 1027, in update_revisions
    overwrite, graph)
  File "/Library/Python/2.6/site-packages/bzrlib/decorators.py", line 194, in write_locked
    result = unbound(self, *args, **kwargs)
  File "/Library/Python/2.6/site-packages/bzrlib/branch.py", line 3399, in update_revisions
    self.target.fetch(self.source, stop_revision)
  File "/Library/Python/2.6/site-packages/bzrlib/decorators.py", line 194, in write_locked
    result = unbound(self, *args, **kwargs)
  File "/Library/Python/2.6/site-packages/bzrlib/branch.py", line 678, in fetch
    pb=pb)
  File "/Library/Python/2.6/site-packages/bzrlib/remote.py", line 1382, in fetch
    find_ghosts=find_ghosts, fetch_spec=fetch_spec)
  File "/Library/Python/2.6/site-packages/bzrlib/decorators.py", line 194, in write_locked
    result = unbound(self, *args, **kwargs)
  File "/Library/Python/2.6/site-packages/bzrlib/repository.py", line 3431, in fetch
    find_ghosts=find_ghosts)
  File "/Library/Python/2.6/site-packages/bzrlib/fetch.py", line 73, in __init__
    self.__fetch()
  File "/Library/Python/2.6/site-packages/bzrlib/fetch.py", line 99, in __fetch
    self._fetch_everything_for_search(search)
  File "/Library/Python/2.6/site-packages/bzrlib/fetch.py", line 127, in _fetch_everything_for_search
    stream, from_format, [])
  File "/Library/Python/2.6/site-packages/bzrlib/remote.py", line 1843, in insert_stream
    (verb, path, resume_tokens) + lock_args, byte_stream)
  File "/Library/Python/2.6/site-packages/bzrlib/smart/client.py", line 181, in call_with_body_stream
    expect_response_body=False)
  File "/Library/Python/2.6/site-packages/bzrlib/smart/client.py", line 81, in _call_and_read_response
    expect_body=expect_response_body),
  File "/Library/Python/2.6/site-packages/bzrlib/smart/message.py", line 306, in read_response_tuple
    _translate_error(self.args)
  File "/Library/Python/2.6/site-packages/bzrlib/smart/message.py", line 361, in _translate_error
    raise errors.ErrorFromSmartServer(error_tuple)
ErrorFromSmartServer: Error received from smart server: ('error', '')

bzr 2.3b4 on python 2.6.1 (Darwin-10.6.0-i386-64bit)
arguments: ['/usr/local/bin/bzr', 'qsubprocess', '--bencode', 'l4:pushe']
encoding: 'UTF-8', fsenc: 'utf-8', lang: 'en_US.UTF-8'
plugins:
  bash_completion /Library/Python/2.6/site-packages/bzrlib/plugins/bash_completion [2.3b4]
  bzrtools /Library/Python/2.6/site-packages/bzrlib/plugins/bzrtools [2.3.0]
  colo /Library/Python/2.6/site-packages/bzrlib/plugins/colo [0.2.1dev]
  email /Library/Python/2.6/site-packages/bzrlib/plugins/email [unknown]
  explorer /Library/Python/2.6/site-packages/bzrlib/plugins/explorer [1.1.3dev]
  extmerge /Users/treaves/.bazaar/plugins/extmerge [unknown]
  fastimport /Library/Python/2.6/site-packages/bzrlib/plugins/fastimport [0.10.0dev]
  keychain /Library/Python/2.6/site-packages/bzrlib/plugins/keychain [0.1.0]
  launchpad /Library/Python/2.6/site-packages/bzrlib/plugins/launchpad [2.3b4]
  loom /Library/Python/2.6/site-packages/bzrlib/plugins/loom [2.2.1dev]
  netrc_credential_store /Library/Python/2.6/site-packages/bzrlib/plugins/netrc_credential_store [2.3b4]
  news_merge /Library/Python/2.6/site-packages/bzrlib/plugins/news_merge [2.3b4]
  pipeline /Library/Python/2.6/site-packages/bzrlib/plugins/pipeline [1.0.0]
  qbzr /Library/Python/2.6/site-packages/bzrlib/plugins/qbzr [0.20.0dev1]
  rewrite /Library/Python/2.6/site-packages/bzrlib/plugins/rewrite [0.6.2dev]
  svn /Library/Python/2.6/site-packages/bzrlib/plugins/svn [1.0.5dev]
  upload /Library/Python/2.6/site-packages/bzrlib/plugins/upload [1.0.0dev]
  xmloutput /Library/Python/2.6/site-packages/bzrlib/plugins/xmloutput [0.8.7.dev]

*** Bazaar has encountered an internal error. This probably indicates a
    bug in Bazaar. You can help us fix it by filing a bug report at
        https://bugs.launchpad.net/bzr/+filebug
    including this traceback and a description of the problem.

[treaves (treaves)]

I've upgraded both client and server to 2.3.0, with no difference.

[Andrew Bennetts (spiv)]

This probably indicates a MemoryError on the server. You should be able to confirm that by looking in the server's bzr log file (probably ~/.bzr.log on the server).

Are you pushing a particularly large number of revisions? Or perhaps committed a particularly large file?

You can probably workaround the error by using SFTP for this push, rather than bzr+ssh.

[Andrew Bennetts (spiv)]

(Btw, I filed the poor error message from the server as bug 722416)

[treaves (treaves)]

Umm... that IS the log I posted. I'm not sure why you've marked this as incomplete, as it is, in fact, complete.

This commit is tiny. Miniscule by any standard post-1982. There are no large files in the repo, and all files in the repo would fit on just about any media made in the last two decades, size-wise.

This is a very serious defect. To just render a repository as unusable is a big deal.

[treaves (treaves)]

This looks to fail after seven of nine files, 42k of a 50k push.

[Martin Pool (mbp)]

treaves, can you please have a look it ~/.bzr.log _on the server_ and if there is an error in that, attach it to this bug.

[treaves (treaves)]

Again, that IS where the log came from.

[Martin Pool (mbp)]

Hi treaves,

You say in the initial description that the client is Mac OS X and the server is Ubuntu. osx stores Python in /Library/Python and Ubuntu puts it in /usr/lib/. The traceback you posted has all paths being under /Library and it says it's running on "python 2.6.1 (Darwin-10.6.0-i386-64bit)". So I really don't think this is the server-side error unless something extremely strange is going on.

Maybe you have the same home-directory NFS-mounted across mutliple machines? In that case you might need to scroll further up in the log file, or look in .bzr.log.old, to find the server-side error.

[treaves (treaves)]

I stand corrected: user error. It was a different bug I had posted the server log on. I apologize.

When watching he server stats while this happens, it does indeed consume all memory, and all swap. Which is seriously wrong. Is there some kind of recursive issue?

Mon 2011-02-21 02:43:44 +0000
0.253 bazaar version: 2.3.0
0.253 bzr arguments: [u'serve', u'--inet', u'--directory=/', u'--allow-writes']
0.340 looking for plugins in /home/treaves/.bazaar/plugins
0.340 looking for plugins in /usr/lib/pymodules/python2.6/bzrlib/plugins
0.369 looking for plugins in /usr/lib/python2.6/dist-packages/bzrlib/plugins
0.395 encoding stdout as osutils.get_user_encoding() 'ANSI_X3.4-1968'
4.487 Auto-packing repository GCRepositoryPackCollection(CHKInventoryRepository('filtered-139766243187216:///opt/bzr/DartsTrainer/.bzr/repository/')), which has 19 pack files, containing 100 revisions. Packing 19 files into 1 affecting 100 revisions
4.488 repacking 100 revisions
4.615 repacking 100 inventories
4.641 repacking chk: 99 id_to_entry roots, 39 p_id_map roots, 138 total keys
4.750 repacking 872 texts
4.859 Adding the key (<bzrlib.btree_index.BTreeGraphIndex object at 0x15d8210>, 10159, 4021575) to an LRUSizeCache failed. value 75541536 is too big to fit in a the cache with size 41943040 52428800
4.892 Adding the key (<bzrlib.btree_index.BTreeGraphIndex object at 0x15d8210>, 10159, 4021575) to an LRUSizeCache failed. value 75541536 is too big to fit in a the cache with size 41943040 52428800
5.016 Adding the key (<bzrlib.btree_index.BTreeGraphIndex object at 0x15d57d0>, 9042, 6832747) to an LRUSizeCache failed. value 90155494 is too big to fit in a the cache with size 41943040 52428800
5.130 Adding the key (<bzrlib.btree_index.BTreeGraphIndex object at 0x15d57d0>, 9042, 6832747) to an LRUSizeCache failed. value 90155494 is too big to fit in a the cache with size 41943040 52428800
5.162 Adding the key (<bzrlib.btree_index.BTreeGraphIndex object at 0x15d8210>, 10159, 4021575) to an LRUSizeCache failed. value 75541536 is too big to fit in a the cache with size 41943040 52428800
5.176 Adding the key (<bzrlib.btree_index.BTreeGraphIndex object at 0x15d8210>, 10159, 4021575) to an LRUSizeCache failed. value 75541536 is too big to fit in a the cache with size 41943040 52428800
5.489 Adding the key (<bzrlib.btree_index.BTreeGraphIndex object at 0x15d57d0>, 9042, 6832747) to an LRUSizeCache failed. value 90155494 is too big to fit in a the cache with size 41943040 52428800
6.723 Adding the key (<bzrlib.btree_index.BTreeGraphIndex object at 0x15d8210>, 10159, 4021575) to an LRUSizeCache failed. value 75541536 is too big to fit in a the cache with size 41943040 52428800
25.895 Adding the key (<bzrlib.btree_index.BTreeGraphIndex object at 0x15d57d0>, 9042, 6832747) to an LRUSizeCache failed. value 90155494 is too big to fit in
a the cache with size 41943040 52428800
64.603 Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.6/bzrlib/smart/request.py", line 355, in _call_converting_errors
    return callable(*args, **kwargs)
  File "/usr/lib/pymodules/python2.6/bzrlib/smart/repository.py", line 760, in _inserter_thread
    stream, ...

[Andrew Bennetts (spiv)]

Thanks for that log.

The key bits of that traceback are:

  File "/usr/lib/pymodules/python2.6/bzrlib/repofmt/pack_repo.py", line 1469, in autopack
    return self._do_autopack()
[...]
  File "_groupcompress_pyx.pyx", line 224, in bzrlib._groupcompress_pyx.DeltaIndex._populate_first_index
AssertionError

Based on comments from John on the mailing list and other bugs, I believe assertion is tripped when a malloc returns NULL, i.e. it's an out of memory error. (Probably we should make it raise MemoryError in that case.) And it's occurring during an autopack, so this looks the same as bug 605480; I'll mark this one as a dupe.

[Andrew Bennetts (spiv)]

Also, that suggests a workaround for now may be to do the pack over a non-smart transport like SFTP from a system with more memory, e.g. "bzr pack sftp://...". That really just postpones the problem, eventually with enough pushes/commits the server will try autopacking all that data (plus the new commits) again, but old data is touched less and less frequently by autopack as the repo grows, so a manual pack from a system with enough memory would probably avoid this problem for many months.

[Martin Pool (mbp)]

On 21 February 2011 15:13, treaves <email address hidden> wrote:
> I stand corrected:  user error.  It was a different bug I had posted the
> server log on.  I apologize.
>
> When watching he server stats while this happens, it does indeed consume
> all memory, and all swap.  Which is seriously wrong.  Is there some kind
> of recursive issue?

Can you please check, on the server, the size of the pack files and of
the total repository directory?

Thanks,

[treaves (treaves)]

The data is below. I have tried sftp, but that fails, for another known critical defect (dealing with renaming pack files). So I'm really stuck. As you can see below, this is a truly trivial amount of data. Most pack files are well under 100k, and the total repository is 100meg.

treaves@development:/opt/bzr$ du -hs Trainer/
100M Trainer/

treaves@development:/opt/bzr/Trainer/.bzr/repository/packs$ dir
total 25716
drwxrwsr-x 2 root bzr 4096 2011-02-21 04:01 .
drwxrwsr-x 7 root bzr 4096 2011-02-13 01:06 ..
-rw-rw-r-- 1 cpesarchick bzr 20698 2011-02-04 04:00 2009619af28df92f9b9be22642e4374b.pack
-rw-rw-r-- 1 treaves bzr 52862 2011-02-06 15:57 23fc111bc69e95de5461fc8ffe41eca8.pack
-rw-rw-r-- 1 cpesarchick bzr 74501 2011-01-22 16:44 31b491b10711f345e21e0b380803760d.pack
-rw-rw-r-- 1 treaves bzr 66304 2011-02-21 04:01 3b1c6bdfb555ffec2e9252262f246e3d.pack
-rw-rw-r-- 1 cpesarchick bzr 629 2011-02-08 02:01 3ccb8db47f07b2ae73f4dd2dab4f9f65.pack
-rw-rw-r-- 1 cpesarchick bzr 41826 2011-02-01 02:32 68d9cb157f93571395a8ce7d425293c2.pack
-rw-rw-r-- 1 root bzr 48102 2010-12-04 03:26 6aad2fd1f9aaf626258614d05e279a97.pack
-rw-rw-r-- 1 treaves bzr 76171 2011-02-13 01:06 6d78892049f5c9f30236b71dd73916dd.pack
-rw-rw-r-- 1 cpesarchick bzr 29305 2011-02-01 03:06 7845ed041135c46c2365439ab913ec18.pack
-rw-rw-r-- 1 root bzr 96851 2010-12-09 02:44 95542073f511f994e53a75a7de36e66a.pack
-rw-rw-r-- 1 cpesarchick bzr 11847 2011-02-04 02:33 9dca536a5d81ed9eede53b4434669203.pack
-rw-rw-r-- 1 cpesarchick bzr 41185 2011-02-18 03:40 a1001a55371b6486373e5ba618ca0571.pack
-rw-rw-r-- 1 cpesarchick bzr 40382 2011-02-18 03:36 b7802f88e2b35bc86c28aeab4d2d5511.pack
-rw-rw-r-- 1 root bzr 6938429 2010-11-28 01:26 bd1bb87204a67684b29b085faa3deb65.pack
-rw-rw-r-- 1 root bzr 75413 2010-12-28 01:24 bd451c25f95ec2aff245af40baf7d029.pack
-rw-rw-r-- 1 root bzr 77047 2010-12-16 02:28 c3beddd752efa22802b1586c217301d0.pack
-rw-rw-r-- 1 treaves bzr 75882 2011-02-05 20:54 c84bf1f83eb37da692d8aa57f2a8e38e.pack
-rw-rw-r-- 1 root bzr 4146790 2010-12-01 20:43 e20ace339241c9c46fdda0618cd9c48d.pack
-rw-rw-r-- 1 treaves bzr 47774 2011-02-06 19:18 e9e7014ef1a7322f48c43dcb7d8ffd23.pack
-rw-rw-r-- 1 cpesarchick bzr 20225 2011-02-03 03:25 f82c41702459ef025d90a3544ef18108.pack
-rw-rw-r-- 1 root bzr 14232997 2010-11-16 04:01 fc3e9aba323fb52fb385d5b05c6816df.pack
treaves@development:/opt/bzr/Trainer/.bzr/repository/packs$