placement api 404 errors are logged poorly

Bug #1626489 reported by Chris Dent
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
Fix Released
Undecided
Chris Dent

Bug Description

In version 1.0 of the placement API, 404 errors are logged at level ERROR with a traceback:

```
2016-09-22 10:37:20.033 22918 ERROR nova.api.openstack.placement.handler [req-8da084c1-467d-488c-941b-af73e18e086d admin admin] Uncaught exception
2016-09-22 10:37:20.033 22918 ERROR nova.api.openstack.placement.handler Traceback (most recent call last):
2016-09-22 10:37:20.033 22918 ERROR nova.api.openstack.placement.handler File "/opt/stack/nova/nova/api/openstack/placement/handler.py", line 171, in __call__
2016-09-22 10:37:20.033 22918 ERROR nova.api.openstack.placement.handler return dispatch(environ, start_response, self._map)
2016-09-22 10:37:20.033 22918 ERROR nova.api.openstack.placement.handler File "/opt/stack/nova/nova/api/openstack/placement/handler.py", line 94, in dispatch
2016-09-22 10:37:20.033 22918 ERROR nova.api.openstack.placement.handler json_formatter=util.json_error_formatter)
2016-09-22 10:37:20.033 22918 ERROR nova.api.openstack.placement.handler HTTPNotFound: The resource could not be found.
2016-09-22 10:37:20.033 22918 ERROR nova.api.openstack.placement.handler
```

This is then immediately followed by an INFO which provides most of what's needed to analyse why a 404 is a 404:

```
2016-09-22 10:37:20.034 22918 INFO nova.api.openstack.placement.requestlog [req-8da084c1-467d-488c-941b-af73e18e086d admin admin] 10.0.2.15 " GET /placement" status: 404 len: 52
```

(note this particular 404 represents a bug in the service ('' and '/' path info should be treated the same), which will be reported in another bug)

First off, a 404 should probably not be logged as an error if we are assuming this is an api that people will be making diverse queries against. However, if we are choosing to log a traceback the not found message should include more information. The reason, at the moment, that there's not much there is that the placement handlers allow a NotFound from the objects in nova/objects/resource_providers.py to rise without being modified (until an outer layer), and those NotFound are bare: they include no messages about what was NotFound as it was assumed the calling context would know.

What should probably happen here is that in the api handler code those places where a NotFound could happen, they should be caught, a debug log message made, and the NotFound transformed into more verbose webob.exc.HTTPNotFound at that layer, not the higher layer.

Chris Dent (cdent)
Changed in nova:
status: New → Confirmed
Revision history for this message
Chris Dent (cdent) wrote :

Discussion with sdague decided no specific need for a LOG.debug, the info log is sufficient.

There are some cases where a NotFound happens for something that is not the resource identified by the URL. Those cases I think are already dealt with and usually lead to an HTTPBadRequest/400.

I'll make this so.

Changed in nova:
assignee: nobody → Chris Dent (cdent)
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to nova (master)

Fix proposed to branch: master
Review: https://review.openstack.org/374955

Changed in nova:
status: Confirmed → In Progress
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to nova (master)

Reviewed: https://review.openstack.org/374955
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=1c859448055236ffb4b63184609b89dd7f5cd322
Submitter: Jenkins
Branch: master

commit 1c859448055236ffb4b63184609b89dd7f5cd322
Author: Chris Dent <email address hidden>
Date: Thu Sep 22 16:03:21 2016 +0000

    [placement] 404 responses do not cause exception logs

    Prior to this change, a 404 caused by a not possible route being
    requested (such as /placement/hello) would result in a proper 404
    response but also a log message about an uncaught exception. This
    made it appear that a 404 response is unexpected and something that
    needs exceptional attention. It doesn't. This change makes sure
    that 404s propagate up the stack in a clean way and are logged only
    by the existing INFO log used for all requests.

    Change-Id: I21f9411bd5154eddc582d5f38891be747de874b3
    Closes-Bug: #1626489

Changed in nova:
status: In Progress → Fix Released
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix included in openstack/nova 15.0.0.0b1

This issue was fixed in the openstack/nova 15.0.0.0b1 development milestone.

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

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