OpenStack Identity (keystone)

SQL connection errors not getting logged or reported

Bug #951958 reported by Joseph Heck on 2012-03-11

This bug affects 1 person

Affects		Status	Importance	Assigned to	Milestone
	OpenStack Identity (keystone)	Fix Released	High	Joseph Heck	OpenStack Identity (keystone) 2012.2 "folsom"

Bug Description

Using a SQL identity backend (mysql) with Keystone, and deep inside keystone I'm getting an OperationalError(..) from the SQL system. This error is captured somewhere deep, and a 500 response and relevant debug logging is occurring with the debug middleware, but the DB log issues aren't being captured.

Using pdb, I was able to step through to get_user_by_name() in the Identity api which was throwing the error for this traceback

traceback:

Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:42 localhost 2012-03-11 02:07:42 Mar 11 02:07:45 localhost 2012-03-11 02:07:45 Mar 11 02:07:45 localhost 2012-03-11 02:07:45 DEBUG [root] ******************** REQUEST ENVIRON ********************
DEBUG [root] SCRIPT_NAME = /v2.0
DEBUG [root] webob.adhoc_attrs = {'response': <Response at 0x32be3d0 200 OK>}
DEBUG [root] REQUEST_METHOD = GET
DEBUG [root] PATH_INFO = /tokens/9885504119e947c38c5879da8fdc68da
DEBUG [root] SERVER_PROTOCOL = HTTP/1.0
DEBUG [root] HTTP_X_AUTH_TOKEN = 7477b56e64811a79aef760ea76cfd5a5
DEBUG [root] eventlet.posthooks = []
DEBUG [root] SERVER_NAME = 172.17.1.100
DEBUG [root] REMOTE_ADDR = 172.17.1.80
DEBUG [root] eventlet.input = <eventlet.wsgi.Input object at 0x2fe1ed0>
DEBUG [root] wsgi.url_scheme = http
DEBUG [root] SERVER_PORT = 35357
DEBUG [root] wsgi.input = <eventlet.wsgi.Input object at 0x2fe1ed0>
DEBUG [root] HTTP_HOST = 172.17.1.80:35357
DEBUG [root] wsgi.multithread = True
DEBUG [root] HTTP_ACCEPT = application/json
DEBUG [root] wsgi.version = (1, 0)
DEBUG [root] openstack.context = {'token_id': '7477b56e64811a79aef760ea76cfd5a5', 'is_admin': True}
DEBUG [root] GATEWAY_INTERFACE = CGI/1.1
DEBUG [root] wsgi.run_once = False
DEBUG [root] wsgi.errors = <open file '<stderr>', mode 'w' at 0x7f69e2a45270>
DEBUG [root] wsgi.multiprocess = False
DEBUG [root] HTTP_X_FORWARDED_FOR = 172.17.1.50
DEBUG [root] CONTENT_TYPE = application/json
DEBUG [root] HTTP_ACCEPT_ENCODING = identity
DEBUG [root]
DEBUG [root] ******************** REQUEST BODY ********************
DEBUG [root]
DEBUG [routes.middleware] Matched GET /tokens/9885504119e947c38c5879da8fdc68da
DEBUG [routes.middleware] Route path: '{path_info:.*}', defaults: {'controller': <keystone.contrib.admin_crud.core.CrudExtension object at 0x2d77590>}
DEBUG [routes.middleware] Match dict: {'controller': <keystone.contrib.admin_crud.core.CrudExtension object at 0x2d77590>, 'path_info': '/tokens/9885504119e947c38c5879da8fdc68da'}
DEBUG [routes.middleware] Matched GET /tokens/9885504119e947c38c5879da8fdc68da
DEBUG [routes.middleware] Route path: '{path_info:.*}', defaults: {'controller': <keystone.service.AdminRouter object at 0x2260190>}
DEBUG [routes.middleware] Match dict: {'controller': <keystone.service.AdminRouter object at 0x2260190>, 'path_info': '/tokens/9885504119e947c38c5879da8fdc68da'}
DEBUG [routes.middleware] Matched GET /tokens/9885504119e947c38c5879da8fdc68da
DEBUG [routes.middleware] Route path: '/tokens/{token_id}', defaults: {'action': u'validate_token', 'controller': <keystone.service.TokenController object at 0x23b5110>}
DEBUG [routes.middleware] Match dict: {'action': u'validate_token', 'token_id': u'9885504119e947c38c5879da8fdc68da', 'controller': <keystone.service.TokenController object at 0x23b5110>}
DEBUG [root] arg_dict: {'token_id': u'9885504119e947c38c5879da8fdc68da'}
DEBUG [eventlet.wsgi.server] Traceback (most recent call last):#012 File "/usr/lib/python2.7/dist-packages/eventlet/wsgi.py", line 336, in handle_one_response#012 result = self.application(self.environ, start_response)#012 File "/usr/lib/python2.7/dist-packages/paste/urlmap.py", line 203, in __call__#012 return app(environ, start_response)#012 File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 147, in __call__#012 resp = self.call_func(req, *args, **self.kwargs)#012 File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 208, in call_func#012 return self.func(req, *args, **kwargs)#012 File "/var/lib/nebula/keystone/keystone/common/wsgi.py", line 285, in __call__#012 response = request.get_response(self.application)#012 File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1053, in get_response#012 application, catch_exc_info=False)#012 File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1022, in call_application#012 app_iter = application(self.environ, start_response)#012 File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 147, in __call__#012 resp = self.call_func(req, *args, **self.kwargs)#012 File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 208, in call_func#012 return self.func(req, *args, **kwargs)#012 File "/var/lib/nebula/keystone/keystone/common/wsgi.py", line 285, in __call__#012 response = request.get_response(self.application)#012 File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1053, in get_response#012 application, catch_exc_info=False)#012 File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1022, in call_application#012 app_iter = application(self.environ, start_response)#012 File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 147, in __call__#012 resp = self.call_func(req, *args, **self.kwargs)#012 File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 208, in call_func#012 return self.func(req, *args, **kwargs)#012 File "/var/lib
DEBUG [eventlet.wsgi.server] 172.17.1.50,172.17.1.80 - - [11/Mar/2012 02:07:45] "GET /v2.0/tokens/9885504119e947c38c5879da8fdc68da HTTP/1.1" 500 7557 3.012415

Joseph Heck (heckj) on 2012-03-11

Changed in keystone:
assignee:	nobody → Joseph Heck (heckj)
importance:	Undecided → High
status:	New → Confirmed

OpenStack Infra (hudson-openstack) on 2012-03-11

Changed in keystone:
status:	Confirmed → In Progress

Revision history for this message

Joseph Heck (heckj) wrote on 2012-03-31:

fix committed with PingListening code update earlier in RC cycle

Changed in keystone:
status:	In Progress → Fix Committed

Joseph Heck (heckj) on 2012-05-20

Changed in keystone:
milestone:	none → folsom-1

Thierry Carrez (ttx) on 2012-05-23

Changed in keystone:
status:	Fix Committed → Fix Released

Thierry Carrez (ttx) on 2012-09-27

Changed in keystone:
milestone:	folsom-1 → 2012.2

Report a bug

This report contains Public information

Everyone can see this information.

You are

Subscribing...

Edit bug mail

Other bug subscribers

Remote bug watches

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