out of memory on commit

Asked by alejandro

I'm getting out of memory error during the commit operation (it stalls for a while showing
'Saving data locally - Stage:repacking texts:texts 14/175') and then aborts.

It's a relatively small repository, and the commit renames 3 files and modifies another 20. Needless to say it had been working perfectly fine for quite some time. I'm running version 2.0.2 on Ubuntu Karmic 32 bits.

Any light on what's going on?

Thanks

Question information

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

Can you please post the traceback from ~/.bzr.log, and also the result of running 'bzr info -v' in your branch.

Revision history for this message
alejandro (alejandrorm) said :
#2

Here it is

>bzr info -v
Standalone tree (format: 2a)
Location:
  branch root: .

Related branches:
    push branch: sftp://[EDITED]
  parent branch: sftp://[EDITED]

Format:
       control: Meta directory format 1
  working tree: Working tree format 6
        branch: Branch format 7
    repository: Repository format 2a - rich roots, group compression and chk inventories

In the working tree:
       219 unchanged
        33 modified
         0 added
         0 removed
         3 renamed
         2 unknown
        67 ignored
        39 versioned subdirectories

Branch history:
        59 revisions
        78 days old
   first revision: Thu 2009-12-10 15:35:19 -0600
  latest revision: Fri 2010-02-26 15:18:08 -0600

Repository:
        59 revisions

> cat ~/.bzr.log
.
.
.
Fri 2010-02-26 18:55:57 -0600
0.026 bzr arguments: [u'ci', u'-m', u'More meaningful error messages']
0.074 looking for plugins in /home/alejandr/.bazaar/plugins
0.191 looking for plugins in /usr/lib/python2.6/dist-packages/bzrlib/plugins
0.240 encoding stdout as sys.stdout encoding 'UTF-8'
0.595 opening working tree '/home/alejandr/work/myProject'
0.630 preparing to commit
[28446] 2010-02-26 18:55:58.119 INFO: Committing to: /home/alejandr/work/myProject/
0.710 Selecting files for commit with filter None
[28446] 2010-02-26 18:55:58.186 INFO: modified build.number
[28446] 2010-02-26 18:55:58.212 INFO: modified src/myproject/BuildNumber.scala
[28446] 2010-02-26 18:55:58.213 INFO: renamed src/myproject/processors/DFDLAssertionException.scala => src/myproject/exceptions/DFDLAssertionException.scala
.
. [EDITED, SEVERAL MORE]
.
.
.
[28446] 2010-02-26 18:55:58.223 INFO: modified src/myproject/xml/XMLUtil.scala
1.139 Auto-packing repository <bzrlib.repofmt.groupcompress_repo.GCRepositoryPackCollection object at 0x935516c>, which has 15 pack files, containing 60 revisions. Packing 10 files into 1 affecting 10 revisions
1.140 repacking 10 revisions
1.230 repacking 10 inventories
1.236 repacking chk: 10 id_to_entry roots, 5 p_id_map roots, 15 total keys
1.290 repacking 176 texts
5.178 Adding the key (<bzrlib.btree_index.BTreeGraphIndex object at 0x9361fcc>, 68043448, 54260077) to an LRUSizeCache failed. value 268148943 is too big to fit in a the cache with size 41943040 52428800
44.453 Adding the key (<bzrlib.btree_index.BTreeGraphIndex object at 0x9361fcc>, 25660, 62892065) to an LRUSizeCache failed. value 1076866082 is too big to fit in a the cache with size 41943040 52428800
52.525 aborting commit write group because of exception:
54.286 Traceback (most recent call last):
  File "/usr/lib/python2.6/dist-packages/bzrlib/commit.py", line 375, in commit
    self.rev_id = self.builder.commit(self.message)
  File "/usr/lib/python2.6/dist-packages/bzrlib/repository.py", line 175, in commit
    self.repository.commit_write_group()
  File "/usr/lib/python2.6/dist-packages/bzrlib/repository.py", line 1554, in commit_write_group
    result = self._commit_write_group()
  File "/usr/lib/python2.6/dist-packages/bzrlib/repofmt/pack_repo.py", line 2268, in _commit_write_group
    hint = self._pack_collection._commit_write_group()
  File "/usr/lib/python2.6/dist-packages/bzrlib/repofmt/pack_repo.py", line 2122, in _commit_write_group
    result = self.autopack()
  File "/usr/lib/python2.6/dist-packages/bzrlib/repofmt/pack_repo.py", line 1472, in autopack
    return self._do_autopack()
  File "/usr/lib/python2.6/dist-packages/bzrlib/repofmt/pack_repo.py", line 1512, in _do_autopack
    reload_func=self._restart_autopack)
  File "/usr/lib/python2.6/dist-packages/bzrlib/repofmt/groupcompress_repo.py", line 691, in _execute_pack_operations
    result = packer.pack()
  File "/usr/lib/python2.6/dist-packages/bzrlib/repofmt/pack_repo.py", line 760, in pack
    return self._create_pack_from_packs()
  File "/usr/lib/python2.6/dist-packages/bzrlib/repofmt/groupcompress_repo.py", line 476, in _create_pack_from_packs
    self._copy_text_texts()
  File "/usr/lib/python2.6/dist-packages/bzrlib/repofmt/groupcompress_repo.py", line 459, in _copy_text_texts
    'texts', self._get_progress_stream, 4)
  File "/usr/lib/python2.6/dist-packages/bzrlib/repofmt/groupcompress_repo.py", line 400, in _copy_stream
    reuse_blocks=False):
  File "/usr/lib/python2.6/dist-packages/bzrlib/groupcompress.py", line 1714, in _insert_record_stream
    bytes = record.get_bytes_as('fulltext')
  File "/usr/lib/python2.6/dist-packages/bzrlib/groupcompress.py", line 454, in get_bytes_as
    self._manager._prepare_for_extract()
  File "/usr/lib/python2.6/dist-packages/bzrlib/groupcompress.py", line 554, in _prepare_for_extract
    self._block._ensure_content(self._last_byte)
  File "/usr/lib/python2.6/dist-packages/bzrlib/groupcompress.py", line 158, in _ensure_content
    self._z_content, num_bytes + _ZLIB_DECOMP_WINDOW)
MemoryError

[28446] 2010-02-26 18:56:51.772 INFO: aborting commit write group: MemoryError()
60.861 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/builtins.py", line 3058, in run
    exclude=safe_relpath_files(tree, exclude))
  File "/usr/lib/python2.6/dist-packages/bzrlib/decorators.py", line 192, 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 192, in write_locked
    result = unbound(self, *args, **kwargs)
  File "/usr/lib/python2.6/dist-packages/bzrlib/mutabletree.py", line 229, in commit
    *args, **kwargs)
  File "/usr/lib/python2.6/dist-packages/bzrlib/commit.py", line 375, in commit
    self.rev_id = self.builder.commit(self.message)
  File "/usr/lib/python2.6/dist-packages/bzrlib/repository.py", line 175, in commit
    self.repository.commit_write_group()
  File "/usr/lib/python2.6/dist-packages/bzrlib/repository.py", line 1554, in commit_write_group
    result = self._commit_write_group()
  File "/usr/lib/python2.6/dist-packages/bzrlib/repofmt/pack_repo.py", line 2268, in _commit_write_group
    hint = self._pack_collection._commit_write_group()
  File "/usr/lib/python2.6/dist-packages/bzrlib/repofmt/pack_repo.py", line 2122, in _commit_write_group
    result = self.autopack()
  File "/usr/lib/python2.6/dist-packages/bzrlib/repofmt/pack_repo.py", line 1472, in autopack
    return self._do_autopack()
  File "/usr/lib/python2.6/dist-packages/bzrlib/repofmt/pack_repo.py", line 1512, in _do_autopack
    reload_func=self._restart_autopack)
  File "/usr/lib/python2.6/dist-packages/bzrlib/repofmt/groupcompress_repo.py", line 691, in _execute_pack_operations
    result = packer.pack()
  File "/usr/lib/python2.6/dist-packages/bzrlib/repofmt/pack_repo.py", line 760, in pack
    return self._create_pack_from_packs()
  File "/usr/lib/python2.6/dist-packages/bzrlib/repofmt/groupcompress_repo.py", line 476, in _create_pack_from_packs
    self._copy_text_texts()
  File "/usr/lib/python2.6/dist-packages/bzrlib/repofmt/groupcompress_repo.py", line 459, in _copy_text_texts
    'texts', self._get_progress_stream, 4)
  File "/usr/lib/python2.6/dist-packages/bzrlib/repofmt/groupcompress_repo.py", line 400, in _copy_stream
    reuse_blocks=False):
  File "/usr/lib/python2.6/dist-packages/bzrlib/groupcompress.py", line 1714, in _insert_record_stream
    bytes = record.get_bytes_as('fulltext')
  File "/usr/lib/python2.6/dist-packages/bzrlib/groupcompress.py", line 454, in get_bytes_as
    self._manager._prepare_for_extract()
  File "/usr/lib/python2.6/dist-packages/bzrlib/groupcompress.py", line 554, in _prepare_for_extract
    self._block._ensure_content(self._last_byte)
  File "/usr/lib/python2.6/dist-packages/bzrlib/groupcompress.py", line 158, in _ensure_content
    self._z_content, num_bytes + _ZLIB_DECOMP_WINDOW)
MemoryError

60.871 return code 3

Revision history for this message
Martin Pool (mbp) said :
#3

This looks like a new bug then.

Revision history for this message
Martin Pool (mbp) said :
#4

Given that nobody else has hit that problem and it's a pretty small commit and repository, I wonder if this has some disk (or sftp) corruption that is making the zlib buffer look unreasonably big.

Could you please try setting

export BZR_PDB=1

then re-run that command; it should put you in a debugger; then type

 p num_bytes
 p self._content_length
 p self._z_content[:100]

Revision history for this message
alejandro (alejandrorm) said :
#5

This is what i get:

(Pdb) p num_bytes
1013974054
(Pdb) p self._content_length
1013974054
(Pdb) p self._z_content[:100]
'x\x9c\x8c\xfdA\xce\xa4Y\xd0\x9e\xe7\r<\xf3*\x08\xce\xcd\xff\x8b\x88\x13\x11\xe7\x10\x94V \x8f<\xf1\x94\x10II\x00)\x12\x14\x81\x9f\xde\x81\x97\xa1\xa5x/\xde\x88_\xd22`\r\xec\xbc&]\x85\xee\xa7Q\xc0\x9d\x8d\xea\xba\x90\x99o\xfc\x9b\xff\xf5\xff\xfe\xff\xf8\x7f\xfe\x1f\xfe\xc5\xbf\xfb\x97\xff\xe9?\xfeO\xff\xf9\x9f\xfc\xe7\x7f\xf7o'
(Pdb)
'x\x9c\x8c\xfdA\xce\xa4Y\xd0\x9e\xe7\r<\xf3*\x08\xce\xcd\xff\x8b\x88\x13\x11\xe7\x10\x94V \x8f<\xf1\x94\x10II\x00)\x12\x14\x81\x9f\xde\x81\x97\xa1\xa5x/\xde\x88_\xd22`\r\xec\xbc&]\x85\xee\xa7Q\xc0\x9d\x8d\xea\xba\x90\x99o\xfc\x9b\xff\xf5\xff\xfe\xff\xf8\x7f\xfe\x1f\xfe\xc5\xbf\xfb\x97\xff\xe9?\xfeO\xff\xf9\x9f\xfc\xe7\x7f\xf7o'

Revision history for this message
Martin Pool (mbp) said :
#6

So it's just a bit over 1GB. It's not particularly a round number and it's plausibly large enough we would have trouble allocating that much memory.

Could you please paste the output of

bzr modified|xargs ls -so

Revision history for this message
alejandro (alejandrorm) said :
#7

Here it is:

> bzr modified|xargs ls -so

 4 -rw------- 1 alejandr 83 2010-03-11 15:55 build.number
 4 -rw------- 1 alejandr 64 2010-02-27 18:04 .bzrignore
 4 -rw------- 1 alejandr 102 2010-03-11 15:55 src/daffodil/BuildNumber.scala
 8 -rw------- 1 alejandr 7585 2010-03-03 13:04 src/daffodil/debugger/BasicTextDebugger.scala
 4 -rw------- 1 alejandr 618 2010-03-03 10:48 src/daffodil/exceptions/DaffodilException.scala
 4 -rw------- 1 alejandr 270 2010-03-03 10:48 src/daffodil/exceptions/DaffodilExceptionUtil.scala
 4 -rw------- 1 alejandr 288 2010-03-03 10:48 src/daffodil/exceptions/ElementNotFoundException.scala
 4 -rw------- 1 alejandr 285 2010-03-03 10:48 src/daffodil/exceptions/ElementNotValidException.scala
 4 -rw------- 1 alejandr 288 2010-03-03 10:48 src/daffodil/exceptions/ElementProcessingException.scala
 4 -rw------- 1 alejandr 297 2010-03-03 10:48 src/daffodil/exceptions/ExpressionDefinitionException.scala
 4 -rw------- 1 alejandr 303 2010-03-03 10:48 src/daffodil/exceptions/SchemaDefinitionException.scala
 4 -rw------- 1 alejandr 313 2010-03-03 10:48 src/daffodil/exceptions/TerminatorNotFoundException.scala
 4 -rw------- 1 alejandr 222 2010-03-03 10:48 src/daffodil/exceptions/UnimplementedException.scala
20 -rw------- 1 alejandr 19934 2010-03-03 12:51 src/daffodil/parser/AnnotationParser.scala
16 -rw------- 1 alejandr 13464 2010-03-03 10:48 src/daffodil/parser/SchemaParser.scala
 4 -rw------- 1 alejandr 2615 2010-03-10 15:11 src/daffodil/processors/input/BasicProcessor.scala
12 -rw------- 1 alejandr 9898 2010-03-10 15:42 src/daffodil/processors/input/BinaryProcessor.scala
 4 -rw------- 1 alejandr 3661 2010-03-10 15:41 src/daffodil/processors/input/CalendarTextProcessor.scala
 4 -rw------- 1 alejandr 2070 2010-03-10 15:38 src/daffodil/processors/input/DebuggingBasicProcessor.scala
 4 -rw------- 1 alejandr 1621 2010-03-10 15:40 src/daffodil/processors/input/DoubleTextProcessor.scala
 4 -rw------- 1 alejandr 1618 2010-03-10 15:40 src/daffodil/processors/input/FloatTextProcessor.scala
 4 -rw------- 1 alejandr 2952 2010-03-10 15:38 src/daffodil/processors/input/InputExpressionProcessor.scala
 4 -rw------- 1 alejandr 1866 2010-03-10 15:39 src/daffodil/processors/input/IntTextProcessor.scala
 4 -rw------- 1 alejandr 1097 2010-03-10 15:37 src/daffodil/processors/input/NullProcessor.scala
 4 -rw------- 1 alejandr 1621 2010-03-10 15:39 src/daffodil/processors/input/NumberTextProcessor.scala
 4 -rw------- 1 alejandr 719 2010-03-10 15:40 src/daffodil/processors/input/StringTextProcessor.scala
24 -rw------- 1 alejandr 20745 2010-03-11 15:54 src/daffodil/processors/input/TextProcessor.scala
 4 -rw------- 1 alejandr 1661 2010-03-03 10:48 src/daffodil/processors/internal/Assert.scala
 4 -rw------- 1 alejandr 1320 2010-03-03 10:48 src/daffodil/processors/internal/Discriminator.scala
 4 -rw------- 1 alejandr 188 2010-03-03 10:48 src/daffodil/processors/internal/InternalProcessor.scala
12 -rw------- 1 alejandr 10338 2010-03-03 10:48 src/daffodil/processors/ProcessorFactory.scala
 4 -rw------- 1 alejandr 3478 2010-03-03 10:48 src/daffodil/processors/VariableMap.scala
 4 -rw------- 1 alejandr 1417 2010-03-03 10:48 src/daffodil/schema/annotation/AnnotationDefaults.scala
 8 -rw------- 1 alejandr 5977 2010-03-11 15:27 src/daffodil/schema/Choice.scala
 8 -rw------- 1 alejandr 6297 2010-03-11 15:27 src/daffodil/schema/ComplexElement.scala
 4 -rw------- 1 alejandr 2820 2010-03-03 10:48 src/daffodil/schema/Element.scala
 8 -rw------- 1 alejandr 4850 2010-03-11 15:27 src/daffodil/schema/Sequence.scala
 8 -rw------- 1 alejandr 5211 2010-03-10 15:10 src/daffodil/schema/SimpleElement.scala
 4 -rw------- 1 alejandr 1206 2010-03-03 10:48 src/daffodil/schema/SimpleExtendedElement.scala
 4 -rw------- 1 alejandr 2887 2010-03-03 10:48 src/daffodil/xml/Namespaces.scala
12 -rw------- 1 alejandr 11998 2010-03-10 15:26 src/daffodil/xml/XMLUtil.scala
 8 -rw------- 1 alejandr 6124 2010-03-11 15:25 srcTest/daffodil/processors/test/unit/InputValueCalcTest.scala
 4 -rw------- 1 alejandr 605 2010-03-03 13:33 test/AO002.xml
 4 -rw------- 1 alejandr 605 2010-03-03 13:33 test/AO003.xml
 4 -rw------- 1 alejandr 1693 2010-03-03 13:14 test/AO.xsd
 4 -rw------- 1 alejandr 605 2010-03-11 15:29 test/output.xml

Revision history for this message
Martin Pool (mbp) said :
#8

Could you please post a listing, including the sizes, of the pack directory? This is during autopack.

I wonder if we should just stop autopacking once they get to say 500MB in size.

Revision history for this message
Robert Collins (lifeless) said :
#9

@Poolie, no, we shouldn't - many big packs gives terrible performance, as does many small packs. Repacking is not very expensive on memory, so its not an obvious culprit here.

Revision history for this message
Robert Collins (lifeless) said :
#10

The backtrace shows that there is a group with 1GB of content in it; we only make groups that big when compressing really big files. Looks like someone has added e.g. a few isos or something.

Can you help with this problem?

Provide an answer of your own, or ask alejandro for more information if necessary.

To post a message you must log in.