KeyError in lru_cache when loggerhead is heavily loaded

Bug #514090 reported by Steve McInerney on 2010-01-29
32
This bug affects 4 people
Affects Status Importance Assigned to Milestone
Bazaar
Critical
Robert Collins
Launchpad itself
High
Michael Hudson-Doyle

Bug Description

Accessing this URL:
http://bazaar.launchpad.net/~bzr-pqm/bzr/bzr.dev/annotate/head%3A/BRANCH.TODO

generated the below in the debug log

INF [20100129-00:10:32.256] [1109903696] loggerhead: Starting to process http://bazaar.launchpad.net/%7Ebzr-pqm/bzr/bzr.dev/annotate/head%3A/BRANCH.TODO
INF [20100129-00:10:32.334] [1109903696] lp-loggerhead: Using branch: ~bzr-pqm/bzr/bzr.dev
INF [20100129-00:10:32.335] [1109903696] lp-loggerhead: branch_url: http://bazaar.launchpad.net/00/03/b0/47
ERR [20100129-00:10:32.680] [1109903696] root: Traceback (most recent call last):
ERR [20100129-00:10:32.680] [1109903696] root: File "/home/pqm/for_rollouts/production/eggs/Paste-1.7.2-py2.5.egg/paste/httpserver.py", line 1062, in process_request_in_thread
ERR [20100129-00:10:32.683] [1109903696] root: File "/usr/lib/python2.5/SocketServer.py", line 254, in finish_request
ERR [20100129-00:10:32.683] [1109903696] root: self.RequestHandlerClass(request, client_address, self)
ERR [20100129-00:10:32.683] [1109903696] root: File "/usr/lib/python2.5/SocketServer.py", line 522, in __init__
ERR [20100129-00:10:32.683] [1109903696] root: self.handle()
ERR [20100129-00:10:32.683] [1109903696] root: File "/home/pqm/for_rollouts/production/eggs/Paste-1.7.2-py2.5.egg/paste/httpserver.py", line 436, in handle
ERR [20100129-00:10:32.685] [1109903696] root: File "/usr/lib/python2.5/BaseHTTPServer.py", line 316, in handle
ERR [20100129-00:10:32.685] [1109903696] root: self.handle_one_request()
ERR [20100129-00:10:32.685] [1109903696] root: File "/home/pqm/for_rollouts/production/eggs/Paste-1.7.2-py2.5.egg/paste/httpserver.py", line 431, in handle_one_request
ERR [20100129-00:10:32.687] [1109903696] root: File "/home/pqm/for_rollouts/production/eggs/Paste-1.7.2-py2.5.egg/paste/httpserver.py", line 287, in wsgi_execute
ERR [20100129-00:10:32.690] [1109903696] root: File "/srv/codebrowse.launchpad.net/production/launchpad-rev-8939/sourcecode/launchpad-loggerhead/launchpad_loggerhead/debug.py", line 106, in wrapped_app
lication
ERR [20100129-00:10:32.690] [1109903696] root: result = application(environ, response_hook)
ERR [20100129-00:10:32.690] [1109903696] root: File "sourcecode/launchpad-loggerhead/start-loggerhead.py", line 150, in wrapped
ERR [20100129-00:10:32.690] [1109903696] root: return app(environ, start_response)
ERR [20100129-00:10:32.690] [1109903696] root: File "/srv/codebrowse.launchpad.net/production/launchpad-rev-8939/sourcecode/launchpad-loggerhead/launchpad_loggerhead/debug.py", line 45, in wrapped
ERR [20100129-00:10:32.690] [1109903696] root: return app(environ, start_response)
ERR [20100129-00:10:32.690] [1109903696] root: File "/home/pqm/for_rollouts/production/eggs/Paste-1.7.2-py2.5.egg/paste/translogger.py", line 68, in __call__
ERR [20100129-00:10:32.692] [1109903696] root: File "/home/pqm/for_rollouts/production/eggs/PasteDeploy-1.3.3-py2.5.egg/paste/deploy/config.py", line 285, in __call__
ERR [20100129-00:10:32.694] [1109903696] root: File "sourcecode/launchpad-loggerhead/start-loggerhead.py", line 134, in wrapped
ERR [20100129-00:10:32.694] [1109903696] root: return app(environ, start_response)
ERR [20100129-00:10:32.695] [1109903696] root: File "/srv/codebrowse.launchpad.net/production/launchpad-rev-8939/sourcecode/launchpad-loggerhead/launchpad_loggerhead/session.py", line 53, in __call__
ERR [20100129-00:10:32.695] [1109903696] root: return self.cookie_handler(environ, start_response)
ERR [20100129-00:10:32.695] [1109903696] root: File "/home/pqm/for_rollouts/production/eggs/Paste-1.7.2-py2.5.egg/paste/auth/cookie.py", line 305, in __call__
ERR [20100129-00:10:32.697] [1109903696] root: File "/srv/codebrowse.launchpad.net/production/launchpad-rev-8939/sourcecode/launchpad-loggerhead/launchpad_loggerhead/session.py", line 73, in _process
ERR [20100129-00:10:32.697] [1109903696] root: return self.application(environ, response_hook)
ERR [20100129-00:10:32.697] [1109903696] root: File "/home/pqm/for_rollouts/production/eggs/Paste-1.7.2-py2.5.egg/paste/httpexceptions.py", line 636, in __call__
ERR [20100129-00:10:32.699] [1109903696] root: File "/srv/codebrowse.launchpad.net/production/launchpad-rev-8939/sourcecode/launchpad-loggerhead/launchpad_loggerhead/app.py", line 230, in __call__
ERR [20100129-00:10:32.699] [1109903696] root: return view.app(environ, start_response)
ERR [20100129-00:10:32.699] [1109903696] root: File "/srv/codebrowse.launchpad.net/production/launchpad-rev-8939/lib/loggerhead/apps/branch.py", line 165, in app
ERR [20100129-00:10:32.699] [1109903696] root: return c(environ, start_response)
ERR [20100129-00:10:32.699] [1109903696] root: File "/srv/codebrowse.launchpad.net/production/launchpad-rev-8939/lib/loggerhead/controllers/__init__.py", line 93, in __call__
ERR [20100129-00:10:32.699] [1109903696] root: vals.update(self.get_values(path, kwargs, headers))
ERR [20100129-00:10:32.699] [1109903696] root: File "/srv/codebrowse.launchpad.net/production/launchpad-rev-8939/lib/loggerhead/controllers/annotate_ui.py", line 149, in get_values
ERR [20100129-00:10:32.699] [1109903696] root: 'contents': list(self.annotate_file(file_id, revid)),
ERR [20100129-00:10:32.700] [1109903696] root: File "/srv/codebrowse.launchpad.net/production/launchpad-rev-8939/lib/loggerhead/controllers/annotate_ui.py", line 52, in annotate_file
ERR [20100129-00:10:32.700] [1109903696] root: file_text = tree.get_file_text(file_id)
ERR [20100129-00:10:32.700] [1109903696] root: File "/home/pqm/for_rollouts/production/eggs/bzr-2.1.0b4-py2.5-linux-x86_64.egg/bzrlib/revisiontree.py", line 68, in get_file_text
ERR [20100129-00:10:32.702] [1109903696] root: File "/home/pqm/for_rollouts/production/eggs/bzr-2.1.0b4-py2.5-linux-x86_64.egg/bzrlib/revisiontree.py", line 79, in iter_files_bytes
ERR [20100129-00:10:32.704] [1109903696] root: File "/home/pqm/for_rollouts/production/eggs/bzr-2.1.0b4-py2.5-linux-x86_64.egg/bzrlib/inventory.py", line 2016, in __getitem__
ERR [20100129-00:10:32.705] [1109903696] root: File "/home/pqm/for_rollouts/production/eggs/bzr-2.1.0b4-py2.5-linux-x86_64.egg/bzrlib/chk_map.py", line 1028, in iteritems
ERR [20100129-00:10:32.707] [1109903696] root: File "/home/pqm/for_rollouts/production/eggs/bzr-2.1.0b4-py2.5-linux-x86_64.egg/bzrlib/chk_map.py", line 1177, in _iter_nodes
ERR [20100129-00:10:32.709] [1109903696] root: File "/home/pqm/for_rollouts/production/eggs/bzr-2.1.0b4-py2.5-linux-x86_64.egg/bzrlib/lru_cache.py", line 366, in add
ERR [20100129-00:10:32.711] [1109903696] root: File "/home/pqm/for_rollouts/production/eggs/bzr-2.1.0b4-py2.5-linux-x86_64.egg/bzrlib/lru_cache.py", line 376, in cleanup
ERR [20100129-00:10:32.713] [1109903696] root: File "/home/pqm/for_rollouts/production/eggs/bzr-2.1.0b4-py2.5-linux-x86_64.egg/bzrlib/lru_cache.py", line 272, in _remove_lru
ERR [20100129-00:10:32.715] [1109903696] root: File "/home/pqm/for_rollouts/production/eggs/bzr-2.1.0b4-py2.5-linux-x86_64.egg/bzrlib/lru_cache.py", line 380, in _remove_node
ERR [20100129-00:10:32.717] [1109903696] root: File "/home/pqm/for_rollouts/production/eggs/bzr-2.1.0b4-py2.5-linux-x86_64.egg/bzrlib/lru_cache.py", line 260, in _remove_node
ERR [20100129-00:10:32.719] [1109903696] root: KeyError: StaticTuple('sha1:c52069ec6ad2056c73cb4bec1b1c51f0f7357db7',)

Related branches

Tom Haddon (mthaddon) wrote :

It seems there are lots of references to /home/pqm/for_rollouts/production as a location here. This is strange, since this is the URL we use to build the code, but it's not on any of the production servers. The build command we run is "make bin/buildout && bin/buildout"

Aaron Bentley (abentley) wrote :

Tom: When you compile a python module to .pyc or .pyo files, this freezes the __file__ value.

Robert Collins (lifeless) wrote :

Ok, consensus here at the bzr sprint is that this is a bug in bzr: we have a non-thread safe module global data structure.
 We are now talking about how to solve it and will move to a patch from there. We can't offer much of a workaround except - perhaps - disable multithreading in loggerhead for now.

Changed in launchpad-code:
status: New → Triaged
importance: Undecided → Critical
assignee: nobody → Robert Collins (lifeless)
Robert Collins (lifeless) wrote :

The branch I have fixed this on is the 2.1 branch, but its newer than LP has deployed. LP can safely cherrypick the last commit on my branch though, to deploy a cherrypick fix.

Robert Collins (lifeless) wrote :

cowboy'd fix is in place, bzr fix is landing in pqm now.

Changed in launchpad-code:
assignee: Robert Collins (lifeless) → nobody
importance: Critical → High
Martin Pool (mbp) wrote :

This is now deployed; test results welcomed.

Thanks to Phillipe for reporting this.

Changed in bzr:
status: New → Fix Released
status: Fix Released → Fix Committed
importance: Undecided → Critical
assignee: nobody → Robert Collins (lifeless)
milestone: none → 2.1.0
Martin Pool (mbp) wrote :
Martin Pool (mbp) on 2010-01-31
summary: - lp-loggerhead smashing on viewing files
+ KeyError in lru_cache when loggerhead is heavily loaded
Changed in launchpad-code:
status: Triaged → In Progress
Martin Pool (mbp) wrote :

This seems to now be merged to 2.1. I'll send it to trunk.

Changed in bzr:
status: Fix Committed → Fix Released
Tim Penhey (thumper) on 2010-02-21
Changed in launchpad-code:
status: In Progress → Fix Released
assignee: nobody → Michael Hudson (mwhudson)
milestone: none → 10.02
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Duplicates of this bug

Other bug subscribers