Launchpad itself

KeyError in lru_cache when loggerhead is heavily loaded

Bug #514090 reported by Steve McInerney
32
This bug affects 4 people
Affects Status Importance Assigned to Milestone
Bazaar
Fix Released
Critical
Robert Collins
Bazaar 2.1.0 "Strasbourg"
Launchpad itself
Fix Released
High
Michael Hudson-Doyle
Launchpad itself 10.02

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',)

Tags: lp-code

Related branches

lp:~lifeless/bzr/bug-514090
Martin Pool: Approve
Diff: 173 lines (+59/-20)
3 files modified
NEWS (+18/-0)
bzrlib/chk_map.py (+35/-14)
bzrlib/tests/test_chk_map.py (+6/-6)
lp:~mwhudson/launchpad/apply-fix-for-bug-513432
Francis J. Lacoste (community): Approve (release-critical)
Tim Penhey (community): Approve
Björn Tillenius: Pending requested
Diff: 13 lines (+2/-1)
1 file modified
versions.cfg (+2/-1)
Revision history for this message
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"

Revision history for this message
Aaron Bentley (abentley) wrote :

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

Revision history for this message
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.

Robert Collins (lifeless)
Changed in launchpad-code:
status: New → Triaged
importance: Undecided → Critical
assignee: nobody → Robert Collins (lifeless)
Revision history for this message
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.

Revision history for this message
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
Revision history for this message
Martin Pool (mbp) wrote :

This is now deployed; test results welcomed.

Thanks to Phillipe for reporting this.

Robert Collins (lifeless)
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
Revision history for this message
Martin Pool (mbp) wrote :

private critical incident report at https://wiki.canonical.com/IncidentReports/2010-01-27-Loggerhead

Martin Pool (mbp)
summary: - lp-loggerhead smashing on viewing files
+ KeyError in lru_cache when loggerhead is heavily loaded
Changed in launchpad-code:
status: Triaged → In Progress
Revision history for this message
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)
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  
Everyone can see this information.

Duplicates of this bug

Subscribing...

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.