Unhelpful error in the keystone log

[Guang Yee]

Occasionally an API (i.e. DELETE /v3/domains/<domain_id>) receives an HTTP 500 response. However, all we got from keystone log is this

2017-09-12 23:20:37.995 7321 WARNING keystone.common.wsgi [req-e1060272-c8b8-4d51-94f5-98b2b4d84a43 960c1d5dba8847cfbde96764ee7747bb - default default -] An unexpected error prevented the server from fulfilling your request.

No traceback. No other helpful messages as to what had caused the HTTP 500. With HTTP 500, I would expect a handsome looking traceback in the keystone log.

So diving into the code, I do see we log the exception if an unexpected error is raise.

https://github.com/openstack/keystone/blob/master/keystone/common/wsgi.py#L248

But, if the error is exception.UnexceptionError, we don't log the exception. We merely log it as a warning.

https://github.com/openstack/keystone/blob/master/keystone/common/wsgi.py#L238

Notice that expection.UnexpectedError is an instance of exception.Error.

https://github.com/openstack/keystone/blob/master/keystone/exception.py#L474

So we have a couple of choices.

1. Find all the places where exception.UnexpectedError is raised. Log something meaningful/actionable prior to raising it.
2. Add a couple of line of code here, https://github.com/openstack/keystone/blob/master/keystone/common/wsgi.py#L238, to log the traceback/exception if e is also an instance of error.UnexpectedError.

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/526939
Committed: https://git.openstack.org/cgit/openstack/keystone/commit/?id=2be384b60c94e6e9d9cee7ee9358ea886b6a193c
Submitter: Zuul
Branch: master

commit 2be384b60c94e6e9d9cee7ee9358ea886b6a193c
Author: Gage Hugo <email address hidden>
Date: Sun Dec 10 12:07:28 2017 -0600

    Improve exception logging with 500 response

    Currently when keystone throws a 500 Error, depending on the actual
    exception type, it can log the message as an exception or as a warning.

    Specifically, if the server throws an exception.UnexpectedError, it
    does not log this as an exception; it simply logs it as a warning. This
    patch set logs the error as an exception if exception.Error is an
    exception.UnexpectedError.

    Change-Id: Ia47cc11378ec64d59b7403cb8a284c764148d7a9
    Co-Authored-By: Tin Lam <email address hidden>
    Closes-Bug: #1717962

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/keystone 13.0.0.0b3 development milestone.