Error during pull: exceptions.AssertionError: Somehow we ended up with too much compressed data, 4019 > 3976

2009/11/5 Ben Jansen <email address hidden>:
> Public bug reported:
>
> I've seen the following assertion error at least a couple times when
> doing a pull to a local branch. I ran ``bzr check'' on the branch and it
> showed no errors.
>
> $ bzr pull
> Using saved parent location: bzr+http://vcs.scm.tripwire.com/bzr/space-dev/scap/
> bzr: ERROR: exceptions.AssertionError: Somehow we ended up with too much compressed data, 4019 > 3976

Hi Ben, thanks for the report.

My first guess would be that something on the network is interfering
with the http traffic, because this is a very low level error. Do you
know if there is a proxy between you and that server, run by either
tripwire.com or your isp? Also, are you able to test access to that
repository over bzr+ssh?

I tried to look at that repo myself but the name does not resolve so I
presume it's an internal host.

--
Martin <http://launchpad.net/~mbp/>

It is an internal host. This is on the same LAN, no proxy or such involved. I suppose there could be some network glitch causing the error, but it's happened to me several times with no other apparent network flakiness. I'll look for other network issues the next time it happens.

Turns out this is a bzr-search error. When I move the .bzr/bzr-search directory, "bzr pull" works. Then, if I put the bzr-search directory back, and run "bzr index", I get the AssertionError described.

This would hint that we might be having difficulties with our 'length estimation' code for a bzr-search index. We are putting data into a zlib compressor, and trying to estimate how long it will be. We estimate by using "zlib.flush(Z_SYNC)" in the stream, and I've seen in the past where the length with a few/bunch of Z_SYNC was actually *smaller* than the length of doing a zlib.compress() of the full data.

I'm guessing something about your data is provoking zlib. Or something about how bzr-search is grabbing terms, etc.

the 3976 is because we use 4096 byte pages, and reserve a 120 byte header for the first page (4096-120 = 3976).

Is there a debug flag I could enable to generate better info for you? Unfortunately, I can't publish the branch in question.

I am seeing the same error in my repository. We run bzr-index each night on each of our repositories. This error is occurring consistently for the last few nights in one out of 16 branches indexed. Local network access without proxy. Here is the message we are getting:

Indexing: /srv/bzr/groups/engineering/curl/rtsp

bzr: ERROR: exceptions.AssertionError: Somehow we ended up with too much compressed data, 4182 > 4096

Traceback (most recent call last):
  File "/usr/lib/python2.6/dist-packages/bzrlib/commands.py", line 842, in exception_to_return_code
    return the_callable(*args, **kwargs)
  File "/usr/lib/python2.6/dist-packages/bzrlib/commands.py", line 1037, in run_bzr
    ret = run(*run_argv)
  File "/usr/lib/python2.6/dist-packages/bzrlib/commands.py", line 654, in run_argv_aliases
    return self.run(**all_cmd_args)
  File "/usr/lib/python2.6/dist-packages/bzrlib/plugins/search/commands.py", line 41, in run
    _mod_index.index_url(trans.base)
  File "/usr/lib/python2.6/dist-packages/bzrlib/plugins/search/index.py", line 150, in index_url
    index.index_branch(branch, _last_revid)
  File "/usr/lib/python2.6/dist-packages/bzrlib/plugins/search/index.py", line 321, in index_branch
    self.index_revisions(branch, revs_to_index)
  File "/usr/lib/python2.6/dist-packages/bzrlib/plugins/search/index.py", line 336, in index_revisions
    outer_bar)
  File "/usr/lib/python2.6/dist-packages/bzrlib/plugins/search/index.py", line 384, in _index_revisions
    self._add_index(builder)
  File "/usr/lib/python2.6/dist-packages/bzrlib/plugins/search/index.py", line 397, in _add_index
    self._upload_transport)
  File "/usr/lib/python2.6/dist-packages/bzrlib/plugins/search/index.py", line 1107, in upload_index
    "terms", writer)
  File "/usr/lib/python2.6/dist-packages/bzrlib/plugins/search/index.py", line 994, in _add_index_to_pack
    index_file = index.finish()
  File "/usr/lib/python2.6/dist-packages/bzrlib/btree_index.py", line 425, in finish
    return self._write_nodes(self.iter_all_entries())[0]
  File "/usr/lib/python2.6/dist-packages/bzrlib/btree_index.py", line 378, in _write_nodes
    self._add_key(string_key, line, rows, allow_optimize=allow_optimize)
  File "/usr/lib/python2.6/dist-packages/bzrlib/btree_index.py", line 313, in _add_key
    rows[-1].finish_node()
  File "/usr/lib/python2.6/dist-packages/bzrlib/btree_index.py", line 67, in finish_node
    byte_lines, _, padding = self.writer.finish()
  File "/usr/lib/python2.6/dist-packages/bzrlib/chunk_writer.py", line 142, in finish
    % (self.bytes_out_len, self.chunk_size))
AssertionError: Somehow we ended up with too much compressed data, 4182 > 4096

bzr 2.0.2 on python 2.6.2 (Linux-2.6.28-16-server-i686-with-Ubuntu-9.04-jaunty)
arguments: ['/usr/bin/bzr', 'index', '/srv/bzr/groups/engineering/curl/rtsp']
encoding: 'ANSI_X3.4-1968', fsenc: 'ANSI_X3.4-1968', lang: None
plugins:
  bzrtools /usr/lib/python2.6/dist-packages/bzrlib/plugins/bzrtools [2.0.0]
  extmerge /usr/lib/python2.6/dist-packages/bzrlib/plugins/extmerge [unknown]
  gtk /usr/lib/python2.6/dist-packages/bzrlib/plugins/gtk [0.98.0...

One of our developers ran into this same problem during a bzr push:

> user@user-linux:~/curl-7.19.7$ bzr push Using saved push
> location: bzr+ssh://bzr/srv/some/path/to/repo/branch/
> No handlers could be found for logger "bzr"
> bzr: ERROR: Server sent an unexpected error: ('error', 'Somehow we ended up with too much compressed data, 4202 > 4096')

This occurred in the same folder where our bzr-index problem occurs each night. The push did run successfully, but the error message is disconcerting. All files in the folder are text files.

bzr-search crashed after running "bzr index" for more than 13 hours (this is a branch that mirrors the Emacs development trunk), very disappointing. Here's the traceback from my .bzr.log:

Sat 2010-01-23 11:51:55 +0200
0.109 bzr arguments: [u'index', u'-v']
0.140 looking for plugins in C:/Documents and Settings/Zaretzky/Application Data/bazaar/2.0/plugins
0.140 looking for plugins in D:/usr/Bazaar/plugins
0.500 encoding stdout as sys.stdout encoding 'cp1252'
49437.140 Traceback (most recent call last):
  File "bzrlib\commands.pyo", line 842, in exception_to_return_code
  File "bzrlib\commands.pyo", line 1037, in run_bzr
  File "bzrlib\commands.pyo", line 654, in run_argv_aliases
  File "D:/usr/Bazaar/plugins\search\commands.py", line 41, in run
  File "D:/usr/Bazaar/plugins\search\index.py", line 150, in index_url
  File "D:/usr/Bazaar/plugins\search\index.py", line 321, in index_branch
  File "D:/usr/Bazaar/plugins\search\index.py", line 336, in index_revisions
  File "D:/usr/Bazaar/plugins\search\index.py", line 384, in _index_revisions
  File "D:/usr/Bazaar/plugins\search\index.py", line 459, in _add_index
  File "D:/usr/Bazaar/plugins\search\index.py", line 397, in _add_index
  File "D:/usr/Bazaar/plugins\search\index.py", line 1262, in upload_index
  File "D:/usr/Bazaar/plugins\search\index.py", line 1235, in combine
  File "D:/usr/Bazaar/plugins\search\index.py", line 1198, in _copy_posting_lists
  File "bzrlib\btree_index.pyo", line 165, in add_node
  File "bzrlib\btree_index.pyo", line 182, in _spill_mem_keys_to_disk
  File "bzrlib\btree_index.pyo", line 218, in _spill_mem_keys_and_combine
  File "bzrlib\btree_index.pyo", line 378, in _write_nodes
  File "bzrlib\btree_index.pyo", line 321, in _add_key
  File "bzrlib\btree_index.pyo", line 90, in finish_node
  File "bzrlib\btree_index.pyo", line 67, in finish_node
  File "bzrlib\chunk_writer.pyo", line 142, in finish
AssertionError: Somehow we ended up with too much compressed data, 3979 > 3976

49437.359 couldn't find apport bug-reporting library: No module named apport
49437.843 Traceback (most recent call last):
  File "bzrlib\plugin.pyo", line 407, in _get__version__
  File "bzrlib\lazy_import.pyo", line 125, in __call__
  File "bzrlib\__init__.pyo", line 112, in _format_version_tuple
ValueError: version_info (1, 1, 0, 'pre', 0) not valid

49437.859 return code 4

When bzr-search indexes it does so incrementally, so that 13 hour task won't be totally lost - you can just run 'bzr index' again to pick up where it left off. However, as John says this looks like a bzr core bug, so I'm reassigning it there, and as high as it will completely block use of this plugin when it occurs - the indices are pretty deterministic.

I'm having this happen pretty much consistently during commits in one repository, though commits to other repositories on the same system generally seem fine. It happened both before and after I performed a bzr upgrade. Running 2.1.2:

Bazaar (bzr) 2.1.2
  Python interpreter: /usr/bin/python 2.5.4
  Python standard library: /usr/lib/python2.5
  Platform: Linux-2.6.26-1-openvz-amd64-x86_64-with-debian-squeeze-sid
  bzrlib: /usr/lib/python2.5/site-packages/bzrlib
  Bazaar configuration: /root/.bazaar
  Bazaar log file: /dev/null

HorsePunchKid, do you ave bzr-search enabled on the repository where you're seeing this bug?

Hi, Jelmer. It does look like I have search 1.7.0dev enabled.

$ bzr plugins | egrep '^\w'
builddeb 2.2.0
bzrtools 2.1.0
launchpad 2.1.2
netrc_credential_store 2.1.2
news_merge 2.1.2
search 1.7.0dev
stats 0.1.0dev
xmloutput 0.8.6

This is the stage that the search pluging appears to hang on, in case it's not clear from the error log above:

| Running pre_commit hooks - Stage:Indexing...:Indexing commits 2/4

I tried a commit with the search plugin disabled, and the commit worked properly.