KeyError exception in remove_recursive_id/find_delete

[Frits Jalvingh]

Using bzr 1.16, when commiting a change containing a set of delete files I got the following exception:
aborting commit write group: KeyError('red_installer.js-20080605213346-1rfly8x1o30bmnb6-8723',)
bzr: ERROR: exceptions.KeyError: 'red_installer.js-20080605213346-1rfly8x1o30bmnb6-8723'

Traceback (most recent call last):
  File "/usr/lib/python2.6/dist-packages/bzrlib/commands.py", line 729, in exception_to_return_code
    return the_callable(*args, **kwargs)
  File "/usr/lib/python2.6/dist-packages/bzrlib/commands.py", line 924, in run_bzr
    ret = run(*run_argv)
  File "/usr/lib/python2.6/dist-packages/bzrlib/commands.py", line 560, in run_argv_aliases
    return self.run(**all_cmd_args)
  File "/usr/lib/python2.6/dist-packages/bzrlib/builtins.py", line 2937, 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 226, 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 228, in commit
    *args, **kwargs)
  File "/usr/lib/python2.6/dist-packages/bzrlib/commit.py", line 363, in commit
    self._update_builder_with_changes()
  File "/usr/lib/python2.6/dist-packages/bzrlib/commit.py", line 644, in _update_builder_with_changes
    self.work_tree, self.basis_revid, iter_changes):
  File "/usr/lib/python2.6/dist-packages/bzrlib/repository.py", line 638, in record_iter_changes
    for change in iter_changes:
  File "/usr/lib/python2.6/dist-packages/bzrlib/commit.py", line 700, in _filter_iter_changes
    self.work_tree.unversion(deleted_ids)
  File "/usr/lib/python2.6/dist-packages/bzrlib/mutabletree.py", line 52, in tree_write_locked
    return unbound(self, *args, **kwargs)
  File "/usr/lib/python2.6/dist-packages/bzrlib/workingtree_4.py", line 1260, in unversion
    self._inventory.remove_recursive_id(file_id)
  File "/usr/lib/python2.6/dist-packages/bzrlib/inventory.py", line 1396, in remove_recursive_id
    to_find_delete = [self._byid[file_id]]
KeyError: 'red_installer.js-20080605213346-1rfly8x1o30bmnb6-8723'

bzr 1.16 on python 2.6.2 (linux2)
arguments: ['/usr/bin/bzr', 'commit']
encoding: 'UTF-8', fsenc: 'UTF-8', lang: 'en_US.UTF-8'
plugins:
  bzrtools /usr/lib/python2.6/dist-packages/bzrlib/plugins/bzrtools [1.16]
  fastimport /home/jal/.bazaar/plugins/fastimport [0.8dev]
  launchpad /usr/lib/python2.6/dist-packages/bzrlib/plugins/launchpad [1.16]
  netrc_credential_store /usr/lib/python2.6/dist-packages/bzrlib/plugins/netrc_credential_store [1.16]
  qbzr /usr/lib/python2.6/dist-packages/bzrlib/plugins/qbzr [0.9.8]
  rebase /home/jal/.bazaar/plugins/rebase [0.5.1dev]
  xmloutput /usr/lib/python2.6/dist-packages/bzrlib/plugins/xmloutput [0.8.3]

A bzr status just before the commit reported:
jal@odeon:~/itrisbzr/vp-trunk$ bzr status
removed:
  viewpoint/WebContent/iRed/Red/Maintenance/Installer/
  viewpoint/WebContent/iRed/Red/Maintenance/Installer/Red_installer.js
  viewpoint/WebContent/iRed/Red/Maintenance/Installer/Red_installerChecks.jsp
  viewpoint/WebContent/iRed/Red/Maintenance/Installer/Red_installerExport.jsp
  viewpoint/WebContent/iRed/Red/Maintenance/Installer/Red_installerMainPage.inc
  viewpoint/WebContent/iRed/Red/Maintenance/Installer/Red_installerMainPage.jsp
  viewpoint/WebContent/iRed/Red/Maintenance/Installer/Red_installerMessage.jsp
  viewpoint/WebContent/iRed/Red/Maintenance/Installer/Red_installerParameters.jsp
  viewpoint/WebContent/iRed/Red/Maintenance/Installer/Red_installerPrintablePage.jsp
  viewpoint/WebContent/iRed/Red/Maintenance/Installer/Red_installerReportHeader.jsp
  viewpoint/WebContent/iRed/Red/Maintenance/Installer/Red_installerReportIndex.jsp
  viewpoint/WebContent/iRed/Red/Maintenance/Installer/Red_installerReportMenu.jsp
  viewpoint/WebContent/iRed/Red/Maintenance/Installer/Red_packager.js
  viewpoint/WebContent/iRed/Red/Maintenance/Installer/Red_packagerBlobViewer.jsp
  viewpoint/WebContent/iRed/Red/Maintenance/Installer/Red_packagerMainPage.jsp
  viewpoint/WebContent/iRed/Red/Maintenance/Installer/Red_packagerModuleFilesIF.jsp
  viewpoint/WebContent/iRed/Red/Maintenance/Installer/Red_packagerSubmitPage.jsp
  viewpoint/WebContent/iRed/Red/Maintenance/Installer/Red_packagerUploadCompleteIF.jsp
  viewpoint/WebContent/iRed/Red/Maintenance/Installer/Red_packagerUploadFilesIF.jsp
  viewpoint/WebContent/iRed/Red/Maintenance/Installer/Red_packagerViewPage.jsp
  viewpoint/WebContent/iRed/Red/Maintenance/Installer/Red_update_blobsEditPage.jsp
  viewpoint/WebContent/iRed/Red/Maintenance/Installer/Red_update_blobsSubmitPage.jsp
  viewpoint/WebContent/iRed/Red/Maintenance/Installer/Red_update_blobsViewPage.jsp
  viewpoint/WebContent/iRed/Red/Maintenance/Installer/_marcus_Red_packagerViewPage.jsp
  viewpoint/WebContent/iRed/Red/updates/updatesSubmitPage.jsp
modified:
  viewpoint/WebContent/iRed/Bae/Maintenance/Bae_Blob_ViewPage.jsp
  viewpoint/WebContent/iRed/Bae/Maintenance/Bae_object_subtypenEditPage.jsp
  viewpoint/WebContent/iRed/Bae/Maintenance/Bae_object_subtypenSubmitPage.jsp
  viewpoint/WebContent/iRed/Extern/Decade/Afschriften/Bae_afschrift_betaalopdrEditPage.jsp
  viewpoint/WebContent/iRed/Kon/Crm_contractenReadPage.jsp
  viewpoint/WebContent/iRed/Vgs/Len/Bae_administratiesEditPage.jsp
  viewpoint/WebContent/iRed/Vgs/Len/Fmp_effect_typenEditPage.jsp
  viewpoint/WebContent/iRed/Wfl/WfactiviteitenReport.jsp

The silly thing is that if I commit again immediately afterwards the commit succeeds!? And this is not an isolated case, I experienced the same behaviour several times now, only in 1.16.

[John Ferlito (johnf-inodes)]

I'm seeing something very similar with 1.16.1

aborting commit write group: KeyError('specification-20090527025523-61x6cd872383vbos-2',)
bzr: ERROR: exceptions.KeyError: 'specification-20090527025523-61x6cd872383vbos-2'

Traceback (most recent call last):
  File "/usr/lib/python2.6/dist-packages/bzrlib/commands.py", line 729, in exception_to_return_code
    return the_callable(*args, **kwargs)
  File "/usr/lib/python2.6/dist-packages/bzrlib/commands.py", line 924, in run_bzr
    ret = run(*run_argv)
  File "/usr/lib/python2.6/dist-packages/bzrlib/commands.py", line 560, in run_argv_aliases
    return self.run(**all_cmd_args)
  File "/usr/lib/python2.6/dist-packages/bzrlib/builtins.py", line 2937, 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 226, 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 228, in commit
    *args, **kwargs)
  File "/usr/lib/python2.6/dist-packages/bzrlib/commit.py", line 363, in commit
    self._update_builder_with_changes()
  File "/usr/lib/python2.6/dist-packages/bzrlib/commit.py", line 644, in _update_builder_with_changes
    self.work_tree, self.basis_revid, iter_changes):
  File "/usr/lib/python2.6/dist-packages/bzrlib/repository.py", line 638, in record_iter_changes
    for change in iter_changes:
  File "/usr/lib/python2.6/dist-packages/bzrlib/commit.py", line 700, in _filter_iter_changes
    self.work_tree.unversion(deleted_ids)
  File "/usr/lib/python2.6/dist-packages/bzrlib/mutabletree.py", line 52, in tree_write_locked
    return unbound(self, *args, **kwargs)
  File "/usr/lib/python2.6/dist-packages/bzrlib/workingtree_4.py", line 1260, in unversion
    self._inventory.remove_recursive_id(file_id)
  File "/usr/lib/python2.6/dist-packages/bzrlib/inventory.py", line 1396, in remove_recursive_id
    to_find_delete = [self._byid[file_id]]
KeyError: 'specification-20090527025523-61x6cd872383vbos-2'

bzr 1.16.1 on python 2.6.2 (linux2)
arguments: ['/usr/bin/bzr', 'commit', '-m', 'upgrade gems and create new cucumber environment']
encoding: 'UTF-8', fsenc: 'UTF-8', lang: 'en_AU.UTF-8'
plugins:
  builddeb /usr/lib/python2.6/dist-packages/bzrlib/plugins/builddeb [unknown]
  bzrtools /usr/lib/python2.6/dist-packages/bzrlib/plugins/bzrtools [1.16]
  launchpad /usr/lib/python2.6/dist-packages/bzrlib/plugins/launchpad [1.16.1]
  netrc_credential_store /usr/lib/python2.6/dist-packages/bzrlib/plugins/netrc_credential_store [1.16.1]
  svn /usr/lib/python2.6/dist-packages/bzrlib/plugins/svn [0.6.2]
*** Bazaar has encountered an internal error.
    Please report a bug at https://bugs.launchpad.net/bzr/+filebug
    including this traceback, and a description ...

[Frits Jalvingh (fjalvingh)]

It is still present in 1.17; I get it for every big commit I'm doing. The odd thing is that if I commit a 2nd time the commit succeeds... Log:
1.502 aborting commit write group because of exception:
1.505 Traceback (most recent call last):
  File "/usr/lib/python2.6/dist-packages/bzrlib/commit.py", line 357, in commit
    self._update_builder_with_changes()
  File "/usr/lib/python2.6/dist-packages/bzrlib/commit.py", line 626, in _update_builder_with_changes
    self.work_tree, self.basis_revid, iter_changes):
  File "/usr/lib/python2.6/dist-packages/bzrlib/repository.py", line 632, in record_iter_changes
    for change in iter_changes:
  File "/usr/lib/python2.6/dist-packages/bzrlib/commit.py", line 682, in _filter_iter_changes
    self.work_tree.unversion(deleted_ids)
  File "/usr/lib/python2.6/dist-packages/bzrlib/mutabletree.py", line 52, in tree_write_locked
    return unbound(self, *args, **kwargs)
  File "/usr/lib/python2.6/dist-packages/bzrlib/workingtree_4.py", line 1231, in unversion
    self._inventory.remove_recursive_id(file_id)
  File "/usr/lib/python2.6/dist-packages/bzrlib/inventory.py", line 1398, in remove_recursive_id
    to_find_delete = [self._byid[file_id]]
KeyError: 'crm_legal_formseditp-20090811162247-a43bdl23eoaurivx-6383'

[24266] 2009-08-11 18:42:10.133 INFO: aborting commit write group: KeyError('crm_legal_formseditp-20090811162247-a43bdl23eoaurivx-6383',)
1.591 Traceback (most recent call last):
  File "/usr/lib/python2.6/dist-packages/bzrlib/commands.py", line 835, in exception_to_return_code
    return the_callable(*args, **kwargs)
  File "/usr/lib/python2.6/dist-packages/bzrlib/commands.py", line 1030, in run_bzr
    ret = run(*run_argv)
  File "/usr/lib/python2.6/dist-packages/bzrlib/commands.py", line 647, in run_argv_aliases
    return self.run(**all_cmd_args)
  File "/usr/lib/python2.6/dist-packages/bzrlib/builtins.py", line 3043, 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 228, in commit
    *args, **kwargs)
  File "/usr/lib/python2.6/dist-packages/bzrlib/commit.py", line 357, in commit
    self._update_builder_with_changes()
  File "/usr/lib/python2.6/dist-packages/bzrlib/commit.py", line 626, in _update_builder_with_changes
    self.work_tree, self.basis_revid, iter_changes):
  File "/usr/lib/python2.6/dist-packages/bzrlib/repository.py", line 632, in record_iter_changes
    for change in iter_changes:
  File "/usr/lib/python2.6/dist-packages/bzrlib/commit.py", line 682, in _filter_iter_changes
    self.work_tree.unversion(deleted_ids)
  File "/usr/lib/python2.6/dist-packages/bzrlib/mutabletree.py", line 52, in tree_write_locked
    return unbound(self, *args, **kwargs)
  File "/usr/lib/python2.6/dist-...

[Robert Collins (lifeless)]

Please try bzr.dev/bzr1.18. I'm pretty sure this is a dup of the stuff I
fixed in 1.18 regarding dirstate integrity.

-Rob

[Frits Jalvingh (fjalvingh)]

I tried with 1.18rc1; it still fails:
bzr: ERROR: exceptions.KeyError: 'allclassesframe.html-20090818220342-82o95wm4i2ljfdtp-709'

Traceback (most recent call last):
  File "/home/jal/bzr-1.18rc1/bzrlib/commands.py", line 835, in exception_to_return_code
    return the_callable(*args, **kwargs)
  File "/home/jal/bzr-1.18rc1/bzrlib/commands.py", line 1030, in run_bzr
    ret = run(*run_argv)
  File "/home/jal/bzr-1.18rc1/bzrlib/commands.py", line 647, in run_argv_aliases
    return self.run(**all_cmd_args)
  File "/home/jal/bzr-1.18rc1/bzrlib/builtins.py", line 3034, in run
    exclude=safe_relpath_files(tree, exclude))
  File "/home/jal/bzr-1.18rc1/bzrlib/decorators.py", line 192, in write_locked
    result = unbound(self, *args, **kwargs)
  File "/home/jal/bzr-1.18rc1/bzrlib/workingtree_4.py", line 197, in commit
    result = WorkingTree3.commit(self, message, revprops, *args, **kwargs)
  File "/home/jal/bzr-1.18rc1/bzrlib/decorators.py", line 192, in write_locked
    result = unbound(self, *args, **kwargs)
  File "/home/jal/bzr-1.18rc1/bzrlib/mutabletree.py", line 228, in commit
    *args, **kwargs)
  File "/home/jal/bzr-1.18rc1/bzrlib/commit.py", line 399, in commit
    self.work_tree.unversion(self.deleted_ids)
  File "/home/jal/bzr-1.18rc1/bzrlib/mutabletree.py", line 52, in tree_write_locked
    return unbound(self, *args, **kwargs)
  File "/home/jal/bzr-1.18rc1/bzrlib/workingtree_4.py", line 1239, in unversion
    self._inventory.remove_recursive_id(file_id)
  File "/home/jal/bzr-1.18rc1/bzrlib/inventory.py", line 1408, in remove_recursive_id
    to_find_delete = [self._byid[file_id]]
KeyError: 'allclassesframe.html-20090818220342-82o95wm4i2ljfdtp-709'

[Frits Jalvingh (fjalvingh)]

The scary thing in -1.18rc1 is that now, when repeating the bzr commit, it goes as follows:
jal@mabillon:~/nbzr/vp-3.2-hot$ bzr commit -m "-3.2 initial"
bzr: ERROR: Working tree is out of date, please run 'bzr update'.
jal@mabillon:~/nbzr/vp-3.2-hot$ bzr update
All changes applied successfully.
Updated to revision 2.
jal@mabillon:~/nbzr/vp-3.2-hot$ bzr commit -m "-3.2 initial"
Committing to: /home/jal/nbzr/vp-3.2-hot/
aborting commit write group: PointlessCommit(No changes to commit)
bzr: ERROR: No changes to commit. Use --unchanged to commit anyhow.

So even though I got an exception something the commit appearently worked. This differs from the behaviour in 1.17.

[Frits Jalvingh (fjalvingh)]

Still present in bzr 2.0.0, and happens a lot when removing subtrees....