(Ariadne Prod) dictionary changed size during iteration

Reported by Jim B. Glenn on 2010-08-20
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
KARL3
Low
Unassigned

Bug Description

reported in error monitor on prod
This happened right after update
Could this just be a glitch of someone hitting site exact time site mod_wsgi was restarting the site?

ENTRY
Fri Aug 20 15:32:44 2010
Exception when processing https://portal.ariadne-network.eu/login.html?came_from=https%3A%2F%2Fportal.ariadne-network.eu%2F
Traceback (most recent call last):
  File "/opt/karl/ariadne/3.3.1-0/src/karl/karl/errorlog.py", line 15, in middleware
    return app(environ, start_response)
  File "/opt/karl/ariadne/3.3.1-0/eggs/repoze.retry-0.9.4-py2.5.egg/repoze/retry/__init__.py", line 88, in __call__
    app_iter = self.application(environ, replace_start_response)
  File "/opt/karl/ariadne/3.3.1-0/eggs/repoze.tm2-1.0a5-py2.5.egg/repoze/tm/__init__.py", line 23, in __call__
    result = self.application(environ, save_status_and_headers)
  File "/opt/karl/ariadne/3.3.1-0/eggs/Paste-1.7.2-py2.5.egg/paste/registry.py", line 350, in __call__
    app_iter = self.application(environ, start_response)
  File "/opt/karl/ariadne/3.3.1-0/eggs/repoze.who-1.0.15-py2.5.egg/repoze/who/middleware.py", line 107, in __call__
    app_iter = app(environ, wrapper.wrap_start_response)
  File "/opt/karl/ariadne/3.3.1-0/eggs/repoze.browserid-0.3-py2.5.egg/repoze/browserid/middleware.py", line 134, in __call__
    app_iter = self.app(environ, wrapper.wrap_start_response)
  File "/opt/karl/ariadne/3.3.1-0/eggs/repoze.bfg-1.2-py2.5.egg/repoze/bfg/router.py", line 130, in __call__
    response = view_callable(context, request)
  File "/opt/karl/ariadne/3.3.1-0/src/karl/karl/views/login.py", line 41, in login_view
    app_url=request.application_url,
  File "/opt/karl/ariadne/3.3.1-0/eggs/repoze.bfg-1.2-py2.5.egg/repoze/bfg/chameleon_zpt.py", line 84, in render_template_to_response
    result = renderer(kw, {})
  File "/opt/karl/ariadne/3.3.1-0/eggs/repoze.bfg-1.2-py2.5.egg/repoze/bfg/chameleon_zpt.py", line 46, in __call__
    result = self.template(**system)
  File "/opt/karl/ariadne/3.3.1-0/eggs/Chameleon-1.1.1-py2.5.egg/chameleon/core/template.py", line 83, in __call__
    return self.render(**kwargs)
  File "/opt/karl/ariadne/3.3.1-0/eggs/Chameleon-1.1.1-py2.5.egg/chameleon/core/template.py", line 335, in render
    return super(TemplateFile, self).render(**kwargs)
  File "/opt/karl/ariadne/3.3.1-0/eggs/Chameleon-1.1.1-py2.5.egg/chameleon/zpt/template.py", line 18, in render
    return super(PageTemplate, self).render(**kwargs)
  File "/opt/karl/ariadne/3.3.1-0/eggs/Chameleon-1.1.1-py2.5.egg/chameleon/core/template.py", line 188, in render
    return self.cook_and_render(kwargs, utils.emptydict, None, True)
  File "/opt/karl/ariadne/3.3.1-0/eggs/Chameleon-1.1.1-py2.5.egg/chameleon/core/template.py", line 315, in cook_and_render
    args, slots, macro, global_scope)
  File "/opt/karl/ariadne/3.3.1-0/eggs/Chameleon-1.1.1-py2.5.egg/chameleon/core/template.py", line 180, in cook_and_render
    return func(econtext, rcontext)
  File "<string>", line 160, in render
  File "/opt/karl/ariadne/3.3.1-0/eggs/Chameleon-1.1.1-py2.5.egg/chameleon/core/template.py", line 379, in render
    return self.render(name, slots=slots, parameters=kwargs)
  File "/opt/karl/ariadne/3.3.1-0/eggs/Chameleon-1.1.1-py2.5.egg/chameleon/zpt/template.py", line 23, in render_macro
    macro, global_scope=global_scope, slots=slots, parameters=parameters)
  File "/opt/karl/ariadne/3.3.1-0/eggs/Chameleon-1.1.1-py2.5.egg/chameleon/core/template.py", line 198, in render_macro
    return self.cook_and_render(parameters, slots, macro, global_scope)
  File "/opt/karl/ariadne/3.3.1-0/eggs/Chameleon-1.1.1-py2.5.egg/chameleon/core/template.py", line 315, in cook_and_render
    args, slots, macro, global_scope)
  File "/opt/karl/ariadne/3.3.1-0/eggs/Chameleon-1.1.1-py2.5.egg/chameleon/core/template.py", line 180, in cook_and_render
    return func(econtext, rcontext)
  File "<string>", line 27, in render
  File "/opt/karl/ariadne/3.3.1-0/eggs/Chameleon-1.1.1-py2.5.egg/chameleon/core/codegen.py", line 29, in lookup_attr
    return getattr(obj, key)
  File "/opt/karl/ariadne/3.3.1-0/src/karl/karl/views/api.py", line 109, in snippets
    self._snippets = get_template('templates/snippets.pt')
  File "/opt/karl/ariadne/3.3.1-0/eggs/repoze.bfg-1.2-py2.5.egg/repoze/bfg/chameleon_zpt.py", line 62, in get_template
    renderer = renderer_factory(path)
  File "/opt/karl/ariadne/3.3.1-0/eggs/repoze.bfg-1.2-py2.5.egg/repoze/bfg/chameleon_zpt.py", line 25, in renderer_factory
    return template_renderer_factory(path, ZPTTemplateRenderer)
  File "/opt/karl/ariadne/3.3.1-0/eggs/repoze.bfg-1.2-py2.5.egg/repoze/bfg/renderers.py", line 63, in template_renderer_factory
    reg.registerUtility(renderer, ITemplateRenderer, name=spec)
  File "/opt/karl/ariadne/3.3.1-0/eggs/zope.component-3.6.0-py2.5.egg/zope/component/registry.py", line 99, in registerUtility
    for ((p, _), data) in self._utility_registrations.iteritems():
RuntimeError: dictionary changed size during iteration

Paul Everitt (paul-agendaless) wrote :

Perhaps Chris can decide if this is worth investigating.

Changed in karl3:
assignee: nobody → Chris Rossi (chris-archimedeanco)
importance: Undecided → Low
milestone: none → m46

This is only sort of related to start up time. The first time that a template is called in BFG, BFG uses the ZCA registry to cache the "renderer" generated for that template. My best guess, looking at the stack trace above, is that another thread attempted to mutate the registry at the same time as this one, probably from another template call and the subsequent caching of the renderer. The registerUtility method of the ZCA registry looks to not be threadsafe as one thread can mutate a Python dictionary while another thread attempts to iterate over its items. I have verified that the same call to iteritems is made in the most recent release of zope.component, so upgrading is not likely to help. This would need to be fixed in zope.component, unless it specifically professes to be non-threadsafe, in which case we would need to implement some sort of locking on the registry at the BFG level. You could think of this as being tangentially related to application startup, since these utility registrations are only

We don't seem to be at very much risk--the potential for hitting this bug has been present since the very beginning of Karl3 and we've never seen it until now, so I'd say this is not very urgent.

Paul Everitt (paul-agendaless) wrote :

Based on Chris's analysis, we're going to skip this one. If it comes back up again and becomes an issue, we'll re-think it.

Changed in karl3:
assignee: Chris Rossi (chris-archimedeanco) → nobody
milestone: m46 → m999
status: New → Won't Fix

It occurs to me that since the common use case for the ZCA registry is to populate it once at start time and then just read it, it may be that threadsafe mutations are not intended to be a part of the design. This might be more appropriately dealt with in BFG, since it is using the ZCA registry in a novel way by mutating it during requests.

Wichert Akkerman (wichert) wrote :

FWIW: I noticed an entry in the python 2.6.6 changelog regarding "RuntimeError: dictionary changed size during iteration". Not sure if that is relevant though.

Chris McDonough (chrism-plope) wrote :

This is fixed on the BFG trunk and the fix will be released in r.bfg 1.3a12.

Download full text (5.3 KiB)

Nice, thanks!

--Paul

On Sep 7, 2010, at 4:49 PM, Chris McDonough wrote:

> This is fixed on the BFG trunk and the fix will be released in r.bfg
> 1.3a12.
>
> --
> (Ariadne Prod) dictionary changed size during iteration
> https://bugs.launchpad.net/bugs/621364
> You received this bug notification because you are subscribed to KARL3.
>
> Status in KARL3: Won't Fix
>
> Bug description:
> reported in error monitor on prod
> This happened right after update
> Could this just be a glitch of someone hitting site exact time site mod_wsgi was restarting the site?
>
> ENTRY
> Fri Aug 20 15:32:44 2010
> Exception when processing https://portal.ariadne-network.eu/login.html?came_from=https%3A%2F%2Fportal.ariadne-network.eu%2F
> Traceback (most recent call last):
> File "/opt/karl/ariadne/3.3.1-0/src/karl/karl/errorlog.py", line 15, in middleware
> return app(environ, start_response)
> File "/opt/karl/ariadne/3.3.1-0/eggs/repoze.retry-0.9.4-py2.5.egg/repoze/retry/__init__.py", line 88, in __call__
> app_iter = self.application(environ, replace_start_response)
> File "/opt/karl/ariadne/3.3.1-0/eggs/repoze.tm2-1.0a5-py2.5.egg/repoze/tm/__init__.py", line 23, in __call__
> result = self.application(environ, save_status_and_headers)
> File "/opt/karl/ariadne/3.3.1-0/eggs/Paste-1.7.2-py2.5.egg/paste/registry.py", line 350, in __call__
> app_iter = self.application(environ, start_response)
> File "/opt/karl/ariadne/3.3.1-0/eggs/repoze.who-1.0.15-py2.5.egg/repoze/who/middleware.py", line 107, in __call__
> app_iter = app(environ, wrapper.wrap_start_response)
> File "/opt/karl/ariadne/3.3.1-0/eggs/repoze.browserid-0.3-py2.5.egg/repoze/browserid/middleware.py", line 134, in __call__
> app_iter = self.app(environ, wrapper.wrap_start_response)
> File "/opt/karl/ariadne/3.3.1-0/eggs/repoze.bfg-1.2-py2.5.egg/repoze/bfg/router.py", line 130, in __call__
> response = view_callable(context, request)
> File "/opt/karl/ariadne/3.3.1-0/src/karl/karl/views/login.py", line 41, in login_view
> app_url=request.application_url,
> File "/opt/karl/ariadne/3.3.1-0/eggs/repoze.bfg-1.2-py2.5.egg/repoze/bfg/chameleon_zpt.py", line 84, in render_template_to_response
> result = renderer(kw, {})
> File "/opt/karl/ariadne/3.3.1-0/eggs/repoze.bfg-1.2-py2.5.egg/repoze/bfg/chameleon_zpt.py", line 46, in __call__
> result = self.template(**system)
> File "/opt/karl/ariadne/3.3.1-0/eggs/Chameleon-1.1.1-py2.5.egg/chameleon/core/template.py", line 83, in __call__
> return self.render(**kwargs)
> File "/opt/karl/ariadne/3.3.1-0/eggs/Chameleon-1.1.1-py2.5.egg/chameleon/core/template.py", line 335, in render
> return super(TemplateFile, self).render(**kwargs)
> File "/opt/karl/ariadne/3.3.1-0/eggs/Chameleon-1.1.1-py2.5.egg/chameleon/zpt/template.py", line 18, in render
> return super(PageTemplate, self).render(**kwargs)
> File "/opt/karl/ariadne/3.3.1-0/eggs/Chameleon-1.1.1-py2.5.egg/chameleon/core/template.py", line 188, in render
> return self.cook_and_render(kwargs, utils.emptydict, None, True)
> File "/opt/karl/ariadne/3.3.1-0/eggs/Chameleon-1.1.1-py2.5.egg/chameleon/core/template.py", line 315, in cook_and_render
> args, slots...

Read more...

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers