yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1235389] Re: Quota violations should not cause a stacktrace in the logs

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Thierry Carrez <thierry.carrez+lp@xxxxxxxxx>
Date: Wed, 22 Jan 2014 16:16:46 -0000
Reply-to: Bug 1235389 <1235389@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
** Changed in: nova
       Status: Fix Committed => Fix Released

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Compute (nova).
https://bugs.launchpad.net/bugs/1235389

Title:
  Quota violations should not cause a stacktrace in the logs

Status in OpenStack Compute (Nova):
  Fix Released

Bug description:
  Right now, when we overrun a quota, we get an ugly stack trace in (at
  least) nova-api's log:

  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack Traceback (most recent call last):
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/api/openstack/__init__.py", line 119, in __call__
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack     return req.get_response(self.application)
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/webob/request.py", line 1296, in send
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack     application, catch_exc_info=False)
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/webob/request.py", line 1260, in call_application
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack     app_iter = application(self.environ, start_response)
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack     return resp(environ, start_response)
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack   File "/opt/stack/new/python-keystoneclient/keystoneclient/middleware/auth_token.py", line 545, in __call__
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack     return self.app(env, start_response)
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack     return resp(environ, start_response)
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack     return resp(environ, start_response)
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack   File "/usr/lib/python2.7/dist-packages/routes/middleware.py", line 131, in __call__
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack     response = self.app(environ, start_response)
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack     return resp(environ, start_response)
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 130, in __call__
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack     resp = self.call_func(req, *args, **self.kwargs)
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack   File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 195, in call_func
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack     return self.func(req, *args, **kwargs)
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/api/openstack/wsgi.py", line 917, in __call__
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack     content_type, body, accept)
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/api/openstack/wsgi.py", line 976, in _process_stack
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack     action_result = self.dispatch(meth, request, action_args)
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/api/openstack/wsgi.py", line 1057, in dispatch
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack     return method(req=request, **action_args)
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/api/openstack/compute/servers.py", line 1248, in _action_resize
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack     return self._resize(req, id, flavor_ref, **kwargs)
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/api/openstack/compute/servers.py", line 1113, in _resize
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack     self.compute_api.resize(context, instance, flavor_id, **kwargs)
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/compute/api.py", line 198, in wrapped
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack     return func(self, context, target, *args, **kwargs)
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/compute/api.py", line 188, in inner
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack     return function(self, context, instance, *args, **kwargs)
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/compute/api.py", line 215, in _wrapped
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack     return fn(self, context, instance, *args, **kwargs)
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/compute/api.py", line 169, in inner
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack     return f(self, context, instance, *args, **kw)
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack   File "/opt/stack/new/nova/nova/compute/api.py", line 2304, in resize
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack     resource=resource)
  2013-10-04 16:23:43.711 24241 TRACE nova.api.openstack TooManyInstances: Quota exceeded for ram: Requested 51137, but already used 128 of 51200 ram

  
  See this example for more:

  http://logs.openstack.org/23/49623/3/check/check-tempest-devstack-vm-
  full/b0d348a/logs/screen-n-api.txt.gz?level=TRACE

  
  This happens a lot, clearly multiple times per every tempest run:

  http://logstash.openstack.org/#eyJzZWFyY2giOiJAbWVzc2FnZTpcIlRvb01hbnlJbnN0YW5jZXM6IFF1b3RhIGV4Y2VlZGVkIGZvciByYW1cIiIsImZpZWxkcyI6W10sIm9mZnNldCI6MCwidGltZWZyYW1lIjoiODY0MDAiLCJncmFwaG1vZGUiOiJjb3VudCIsInRpbWUiOnsidXNlcl9pbnRlcnZhbCI6MH0sInN0YW1wIjoxMzgwOTA5MzQ3MjQ3fQ==

To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1235389/+subscriptions