lazy load operation of attribute 'metadata' cannot proceed

[Eldar Nugaev]

2011-05-20 18:50:06,693 routes.middleware: Matched GET /servers/detail
2011-05-20 18:50:06,693 routes.middleware: Route path: '/servers/detail', defaults: {'action': u'detail', 'controller': <nova.api.openstack.servers.ControllerV10 object at 0x1f71890>}
2011-05-20 18:50:06,694 routes.middleware: Match dict: {'action': u'detail', 'controller': <nova.api.openstack.servers.ControllerV10 object at 0x1f71890>}
2011-05-20 18:50:06,694 nova.wsgi: GET http://172.16.128.236:8774/v1.0/servers/detail?fresh=1305903006.65
2011-05-20 18:50:06,833 nova.api.openstack: Caught error: Parent instance <Instance at 0x29a4ed0> is not bound to a Session; lazy load operation of attribute 'metadata' cannot proceed
(nova.api.openstack): TRACE: Traceback (most recent call last):
(nova.api.openstack): TRACE: File "/usr/lib/python2.6/site-packages/nova/api/openstack/__init__.py", line 59, in __call__
(nova.api.openstack): TRACE: return req.get_response(self.application)
(nova.api.openstack): TRACE: File "/usr/lib/python2.6/site-packages/webob/request.py", line 919, in get_response
(nova.api.openstack): TRACE: application, catch_exc_info=False)
(nova.api.openstack): TRACE: File "/usr/lib/python2.6/site-packages/webob/request.py", line 887, in call_application
(nova.api.openstack): TRACE: app_iter = application(self.environ, start_response)
(nova.api.openstack): TRACE: File "/usr/lib/python2.6/site-packages/webob/dec.py", line 159, in __call__
(nova.api.openstack): TRACE: return resp(environ, start_response)
(nova.api.openstack): TRACE: File "/usr/lib/python2.6/site-packages/webob/dec.py", line 159, in __call__
(nova.api.openstack): TRACE: return resp(environ, start_response)
(nova.api.openstack): TRACE: File "/usr/lib/python2.6/site-packages/webob/dec.py", line 159, in __call__
(nova.api.openstack): TRACE: return resp(environ, start_response)
(nova.api.openstack): TRACE: File "/usr/lib/python2.6/site-packages/routes/middleware.py", line 131, in __call__
(nova.api.openstack): TRACE: response = self.app(environ, start_response)
(nova.api.openstack): TRACE: File "/usr/lib/python2.6/site-packages/webob/dec.py", line 159, in __call__
(nova.api.openstack): TRACE: return resp(environ, start_response)
(nova.api.openstack): TRACE: File "/usr/lib/python2.6/site-packages/webob/dec.py", line 147, in __call__
(nova.api.openstack): TRACE: resp = self.call_func(req, *args, **self.kwargs)
(nova.api.openstack): TRACE: File "/usr/lib/python2.6/site-packages/webob/dec.py", line 208, in call_func
(nova.api.openstack): TRACE: return self.func(req, *args, **kwargs)
(nova.api.openstack): TRACE: File "/usr/lib/python2.6/site-packages/nova/wsgi.py", line 361, in __call__
(nova.api.openstack): TRACE: result = method(**arg_dict)
(nova.api.openstack): TRACE: File "/usr/lib/python2.6/site-packages/nova/api/openstack/servers.py", line 76, in detail
(nova.api.openstack): TRACE: return self._items(req, is_detail=True)
(nova.api.openstack): TRACE: File "/usr/lib/python2.6/site-packages/nova/api/openstack/servers.py", line 102, in _items
(nova.api.openstack): TRACE: for inst in limited_list]
(nova.api.openstack): TRACE: File "/usr/lib/python2.6/site-packages/nova/api/openstack/views/servers.py", line 45, in build
(nova.api.openstack): TRACE: server = self._build_detail(inst)
(nova.api.openstack): TRACE: File "/usr/lib/python2.6/site-packages/nova/api/openstack/views/servers.py", line 86, in _build_detail
(nova.api.openstack): TRACE: for item in inst.get('metadata', []):
(nova.api.openstack): TRACE: File "/usr/lib/python2.6/site-packages/nova/db/sqlalchemy/models.py", line 77, in get
(nova.api.openstack): TRACE: return getattr(self, key, default)
(nova.api.openstack): TRACE: File "/usr/lib64/python2.6/site-packages/sqlalchemy/orm/attributes.py", line 163, in __get__
(nova.api.openstack): TRACE: instance_dict(instance))
(nova.api.openstack): TRACE: File "/usr/lib64/python2.6/site-packages/sqlalchemy/orm/attributes.py", line 383, in get
(nova.api.openstack): TRACE: value = callable_(passive=passive)
(nova.api.openstack): TRACE: File "/usr/lib64/python2.6/site-packages/sqlalchemy/orm/strategies.py", line 595, in __call__
(nova.api.openstack): TRACE: (mapperutil.state_str(state), self.key)
(nova.api.openstack): TRACE: DetachedInstanceError: Parent instance <Instance at 0x29a4ed0> is not bound to a Session; lazy load operation of attribute 'metadata' cannot proceed
(nova.api.openstack): TRACE:

[Thierry Carrez (ttx)]

@Eldar: could you precise the conditions to reproduce the bug ? If you're working on this, could you set the bug status to 'In progress' ?

[Eldar Nugaev (reldan)]

It looks to be https://bugs.launchpad.net/nova/+bug/757293 error in OpenStack API in servers/detail

[Brian Lamar (blamar)]

Hey Eldar, I'm getting this error a lot and before looking at it myself I'm curious if you've made any progress on this. Thanks!

[Jay Pipes (jaypipes)]

This should be an easy fix. Basically, the instance_ref returned from some function needs to have a session object bound to it. Look around line 102 in nova/api/openstack/servers.py for whereever the "limited_list" variable is populated. That function is returning a list of instance objects, and those instance objects need to have a session bound to them. To bind a session to the object, you just need to do:

object.session = some_session_object

some_session_object is typically an optional parameter to most of the sqlalchemy db api calls, and if None, the get_session() function returns a new session object.

Hope this helps...
-jay

[Brian Lamar (blamar)]

Hey Jay, I'm afraid it might not be quite as simple as that. This bug is intermittent, so I'm a bit baffled where the session is being lost as it works some times and doesn't work other times.

[Vish Ishaya (vishvananda)]

Generally this is due to a missing joinedload statement in the query. To get data from a related table, it must be loaded in the initial query, since our objects no longer have a sesssion attached when they return from the db layer. So somehow the instance is getting retrieved from the db without the joinedload. We had a similar issue at one point in the ec2_metadata server because it was using instance_get_all instead of instance_get which didn't have the proper joinedload. Could this be a similar issue?

Vish

On Jun 8, 2011, at 1:27 PM, Brian Lamar wrote:

> Hey Jay, I'm afraid it might not be quite as simple as that. This bug is
> intermittent, so I'm a bit baffled where the session is being lost as it
> works some times and doesn't work other times.
>
> --
> You received this bug notification because you are a member of Nova Bug
> Team, which is subscribed to OpenStack Compute (nova).
> https://bugs.launchpad.net/bugs/785816
>
> Title:
> lazy load operation of attribute 'metadata' cannot proceed
>
> Status in OpenStack Compute (Nova):
> In Progress
>
> Bug description:
> 2011-05-20 18:50:06,693 routes.middleware: Matched GET /servers/detail
> 2011-05-20 18:50:06,693 routes.middleware: Route path: '/servers/detail', defaults: {'action': u'detail', 'controller': <nova.api.openstack.servers.ControllerV10 object at 0x1f71890>}
> 2011-05-20 18:50:06,694 routes.middleware: Match dict: {'action': u'detail', 'controller': <nova.api.openstack.servers.ControllerV10 object at 0x1f71890>}
> 2011-05-20 18:50:06,694 nova.wsgi: GET http://172.16.128.236:8774/v1.0/servers/detail?fresh=1305903006.65
> 2011-05-20 18:50:06,833 nova.api.openstack: Caught error: Parent instance <Instance at 0x29a4ed0> is not bound to a Session; lazy load operation of attribute 'metadata' cannot proceed
> (nova.api.openstack): TRACE: Traceback (most recent call last):
> (nova.api.openstack): TRACE: File "/usr/lib/python2.6/site-packages/nova/api/openstack/__init__.py", line 59, in __call__
> (nova.api.openstack): TRACE: return req.get_response(self.application)
> (nova.api.openstack): TRACE: File "/usr/lib/python2.6/site-packages/webob/request.py", line 919, in get_response
> (nova.api.openstack): TRACE: application, catch_exc_info=False)
> (nova.api.openstack): TRACE: File "/usr/lib/python2.6/site-packages/webob/request.py", line 887, in call_application
> (nova.api.openstack): TRACE: app_iter = application(self.environ, start_response)
> (nova.api.openstack): TRACE: File "/usr/lib/python2.6/site-packages/webob/dec.py", line 159, in __call__
> (nova.api.openstack): TRACE: return resp(environ, start_response)
> (nova.api.openstack): TRACE: File "/usr/lib/python2.6/site-packages/webob/dec.py", line 159, in __call__
> (nova.api.openstack): TRACE: return resp(environ, start_response)
> (nova.api.openstack): TRACE: File "/usr/lib/python2.6/site-packages/webob/dec.py", line 159, in __call__
> (nova.api.openstack): TRACE: return resp(environ, start_response)
> (nova.api.openstack): TRACE: File "/usr/lib/python2.6/site-packages/routes/middleware.py", line 131, in __call__
> (nova.api.openstack): TRACE: response...

[Brian Lamar (blamar)]

Looks like instance_get_all() in sqlalchemy.api is using joinedload on metadata:

return session.query(models.Instance).\
                   options(joinedload_all('fixed_ip.floating_ips')).\
                   options(joinedload('security_groups')).\
                   options(joinedload_all('fixed_ip.network')).\
                   options(joinedload('metadata')).\
                   options(joinedload('instance_type')).\
                   filter_by(deleted=can_read_deleted(context)).\
                   all()

I have no idea where to even start looking for the root cause of this bug.