Stack trace returned to end-user

[Tim Hinrichs]

We probably don't want to expose stack traces to users--that's the point of having good error messages. But today we're getting that traceback as part of the error message output.

$ openstack congress policy row list bob p
Not Found::table 'p' doesn't exist
Traceback (most recent call last):

  File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/server.py", line 133, in _process_incoming
    res = self.dispatcher.dispatch(message)

  File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 150, in dispatch
    return self._do_dispatch(endpoint, method, ctxt, args)

  File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 121, in _do_dispatch
    result = func(ctxt, **new_args)

  File "/opt/stack/congress/congress/policy_engines/agnostic.py", line 2357, in get_row_data
    return self.dse.get_row_data(table_id, source_id, trace)

  File "/opt/stack/congress/congress/policy_engines/agnostic.py", line 807, in get_row_data
    raise exception.NotFound("table '%s' doesn't exist" % table_id)

NotFound: table 'p' doesn't exist

[Tim Hinrichs (thinrichs)]

Found some others ...

$ openstack congress policy rule list bob
$ openstack congress policy row list alice 'p(x)'

[Aimee Ukasick (aimeeu)]

I wonder if changing e.message to str(e) caused this

[Aimee Ukasick (aimeeu)]

This happens with a direct call to the API as well.
I don't recall the traceback being included last month.

[Aimee Ukasick (aimeeu)]

Note that the traceback is NOT displayed with openstack congress datasource row list bob p so only a problem with policy calls

[Aimee Ukasick (aimeeu)]

openstack congress driver schema show bubba
Driver not found None (HTTP 404) (Request-ID: req-ff812722-9bf5-42b8-bb85-cf9cf223b780)

openstack congress datasource row list bob p
Resource bob not found (HTTP 404)

openstack congress policy row list bob p
Not Found::table 'p' doesn't exist
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/server.py", line 133, in _process_incoming
    res = self.dispatcher.dispatch(message)
  File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 150, in dispatch
    return self._do_dispatch(endpoint, method, ctxt, args)
  File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 121, in _do_dispatch
    result = func(ctxt, **new_args)
  File "/opt/stack/congress/congress/policy_engines/agnostic.py", line 2362, in get_row_data
    return self.dse.get_row_data(table_id, source_id, trace)
  File "/opt/stack/congress/congress/policy_engines/agnostic.py", line 894, in get_row_data
    raise KeyError("Table '%s' doesn't exist" % table_id)
NotFound: table 'p' doesn't exist
 (HTTP 404) (Request-ID: req-e0fe5485-1b2c-4f25-8d2c-55f8be9a4269)

[Aimee Ukasick (aimeeu)]

Confirmed that API and CLI calls to datasource and schema do not return traceback when invalid IDs are passed. "datasource" appears to be the only one of the three displaying user-friendly error information as expected.

openstack congress datasource schema show bad-ds-id
Resource bad-ds-id not found (HTTP 404)
curl -X GET -H "X-Auth-Token: 081efa26afe34c9faf2a229f7ee0f0b2" -H "Cache-Control: no-cache" "http://192.168.56.103:1789/v1/data-sources/bad-ds-id/schema"
{
  "error": {
    "message": "service 'bad-ds-id' could not be found",
    "error_data": null,
    "error_code": 404
  }
}

*****A CLI call to get info about a driver displays a Request-ID
openstack congress driver config show invalid-driver-id
Driver not found None (HTTP 404) (Request-ID: req-17bdab1e-1e71-4d81-8fb3-22dbf859cfbd)
curl -X GET -H "X-Auth-Token: 081efa26afe34c9faf2a229f7ee0f0b2" -H "Cache-Control: no-cache" "http://192.168.56.103:1789/v1/system/drivers/invalid-driver-id"
{
  "error": {
    "message": "Driver not found None",
    "error_data": null,
    "error_code": 404
  }
}

*****The error/not found handling for policies seems to be inconsistent. The first two examples below return a 404. The third: the CLI returns HTTP 400 but the API returns and error code of 1020 (which maps to HTTP 404)

curl -X GET -H "X-Auth-Token: 5a3b135235e045049a8f883370c675c0" -H "Cache-Control: no-cache" "http://192.168.56.103:1789/v1/policies/bad-policy-id"
{
  "error": {
    "message": "Not Found::No policy found with name or id bad-policy-id\nTraceback (most recent call last):\n\n File \"/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/server.py\", line 133, in _process_incoming\n res = self.dispatcher.dispatch(message)\n\n File \"/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py\", line 150, in dispatch\n return self._do_dispatch(endpoint, method, ctxt, args)\n\n File \"/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py\", line 121, in _do_dispatch\n result = func(ctxt, **new_args)\n\n File \"/opt/stack/congress/congress/policy_engines/agnostic.py\", line 2318, in persistent_get_policy\n return self.dse.persistent_get_policy(id_)\n\n File \"/opt/stack/congress/congress/policy_engines/agnostic.py\", line 398, in persistent_get_policy\n 'No policy found with name or id %s' % id_)\n\nNotFound: No policy found with name or id bad-policy-id\n",
    "error_data": null,
    "error_code": 404
  }
}

openstack congress policy row list bob p
Not Found::table 'p' doesn't exist
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/server.py", line 133, in _process_incoming
    res = self.dispatcher.dispatch(message)
  File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 150, in dispatch
    return self._do_dispatch(endpoint, method, ctxt, args)
  File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 121, in _do_dispatch
    result = func(ctxt, **new_args)
  File "/opt/stack/congress/congress/policy_engines/agnostic.py", line 2362, in get_row_data
    return self.dse.get_row_data(table_id, source_id, trace)
  ...

[Eric K (ekcs)]

Thanks for such a detailed investigation, Aimee!

As someone mentioned over ML, Oslo messaging appends the traceback to e.args[0] of the remote exception on RPC call.
https://github.com/openstack/oslo.messaging/blob/5690156d9b73e39547dbc3d27b12b41321bb6500/oslo_messaging/_drivers/common.py#L207
https://github.com/openstack/oslo.messaging/blob/5690156d9b73e39547dbc3d27b12b41321bb6500/oslo_messaging/_drivers/common.py#L242

In Python2, the e.message field is left untouched by oslo messaging, so taking that avoids the traceback. In Python3 however, that field does not exist.

So as far as I can figure, the only Python2+3 way to avoid the traceback is to "undo" what oslo messaging does to e.args[0]

I'm working on a patch.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/newton
Review: https://review.openstack.org/379036

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/375183
Committed: https://git.openstack.org/cgit/openstack/congress/commit/?id=7f4c6bdeb8a4128faca9ae22eaed37792d64cbb0
Submitter: Jenkins
Branch: master

commit 7f4c6bdeb8a4128faca9ae22eaed37792d64cbb0
Author: Eric K <email address hidden>
Date: Thu Sep 22 18:12:02 2016 -0700

    Remove the traceback added by oslo-messaging RPC

    Remove the traceback added by oslo-messaging RPC, to avoid
    displaying traceback to user.

    Some requests that return traceback w/o this patch, now normal:
    $ openstack congress policy row list bob p
    Not Found::table 'p' doesn't exist (HTTP 404) (Request-ID: req-54c2a117-0306-4fd2-8d71-8f7e6d130a43)
    $ openstack congress policy rule list bob
    The specified policy does not exist.::Policy ID bob does not exist
    (HTTP 400) (Request-ID: req-d85db619-afa0-4977-99f8-0dc88c5daa0c)
    $ openstack congress policy delete bob
    Policy Name or ID 'bob' does not exist (HTTP 404) (Request-ID: req-e1a70735-f469-4fae-b278-f061b64f4298)
    $ openstack congress policy show bob
    Resource bob not found (HTTP 404)

    The 400 error should be addressed in separate patch.

    Change-Id: Ia6b2b3e9816c90d4ca6b687cca2fac90eb5fb9b3
    Closes-Bug: #1620868

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/379036
Committed: https://git.openstack.org/cgit/openstack/congress/commit/?id=c9bfcdd0fe4c66f5766e62f03f8eea598954520d
Submitter: Jenkins
Branch: stable/newton

commit c9bfcdd0fe4c66f5766e62f03f8eea598954520d
Author: Eric K <email address hidden>
Date: Thu Sep 22 18:12:02 2016 -0700

    Remove the traceback added by oslo-messaging RPC

    Remove the traceback added by oslo-messaging RPC, to avoid
    displaying traceback to user.

    Some requests that return traceback w/o this patch, now normal:
    $ openstack congress policy row list bob p
    Not Found::table 'p' doesn't exist (HTTP 404) (Request-ID: req-54c2a117-0306-4fd2-8d71-8f7e6d130a43)
    $ openstack congress policy rule list bob
    The specified policy does not exist.::Policy ID bob does not exist
    (HTTP 400) (Request-ID: req-d85db619-afa0-4977-99f8-0dc88c5daa0c)
    $ openstack congress policy delete bob
    Policy Name or ID 'bob' does not exist (HTTP 404) (Request-ID: req-e1a70735-f469-4fae-b278-f061b64f4298)
    $ openstack congress policy show bob
    Resource bob not found (HTTP 404)

    The 400 error should be addressed in separate patch.

    Change-Id: Ia6b2b3e9816c90d4ca6b687cca2fac90eb5fb9b3
    Closes-Bug: #1620868

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/congress 4.0.0.0rc2 release candidate.

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/congress 5.0.0.0b1 development milestone.