os-simple-tenant-usage: printing trace in logs if not passing all requirements

Bug #1300972 reported by Lauren Taylor
10
This bug affects 2 people
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
Fix Released
Medium
Christopher Yeoh
Icehouse
Fix Released
Medium
Matt Riedemann

Bug Description

REST os-simple-tenant-usage is returning with a response code 400

from api.log:
2014-03-20 11:27:58.044 49351 INFO nova.osapi_compute.wsgi.server [req-b653843a-de1c-4267-af33-7f7a9c5fa99d 0 b38c2504810f437883a5b57a8b13fe7f] 9.41.223.193,127.0.0.1 "GET /v2/b38c2504810f437883a5b57a8b13fe7f/os-simpletenant-usage HTTP/1.1" status: 404 len: 302 time: 0.6078889
2014-03-20 11:28:04.221 49351 ERROR nova.api.openstack.wsgi [req-09d455d6-c963-4729-b1b6-082bd04cfe8b 0 b38c2504810f437883a5b57a8b13fe7f] NV-46FDF46 Exception handling resource: strptime() argument 1 must be string, not None
2014-03-20 11:28:04.221 49351 TRACE nova.api.openstack.wsgi Traceback (most recent call last):
2014-03-20 11:28:04.221 49351 TRACE nova.api.openstack.wsgi File "/usr/lib/python2.6/site-packages/nova/api/openstack/wsgi.py", line 991, in _process_stack
2014-03-20 11:28:04.221 49351 TRACE nova.api.openstack.wsgi action_result = self.dispatch(meth, request, action_args)
2014-03-20 11:28:04.221 49351 TRACE nova.api.openstack.wsgi File "/usr/lib/python2.6/site-packages/nova/api/openstack/wsgi.py", line 1078, in dispatch
2014-03-20 11:28:04.221 49351 TRACE nova.api.openstack.wsgi return method(req=request, **action_args)
2014-03-20 11:28:04.221 49351 TRACE nova.api.openstack.wsgi File "/usr/lib/python2.6/site-packages/nova/api/openstack/compute/contrib/simple_tenant_usage.py", line 252, in index
2014-03-20 11:28:04.221 49351 TRACE nova.api.openstack.wsgi (period_start, period_stop, detailed) = self._get_datetime_range(req)
2014-03-20 11:28:04.221 49351 TRACE nova.api.openstack.wsgi File "/usr/lib/python2.6/site-packages/nova/api/openstack/compute/contrib/simple_tenant_usage.py", line 234, in _get_datetime_range
2014-03-20 11:28:04.221 49351 TRACE nova.api.openstack.wsgi period_start = self._parse_datetime(env.get('start', [None])[0])
2014-03-20 11:28:04.221 49351 TRACE nova.api.openstack.wsgi File "/usr/lib/python2.6/site-packages/nova/api/openstack/compute/contrib/simple_tenant_usage.py", line 220, in _parse_datetime
2014-03-20 11:28:04.221 49351 TRACE nova.api.openstack.wsgi value = timeutils.parse_strtime(dtstr, "%Y-%m-%d %H:%M:%S.%f")
2014-03-20 11:28:04.221 49351 TRACE nova.api.openstack.wsgi File "/usr/lib/python2.6/site-packages/nova/openstack/common/timeutils.py", line 65, in parse_strtime
2014-03-20 11:28:04.221 49351 TRACE nova.api.openstack.wsgi return datetime.datetime.strptime(timestr, fmt)
2014-03-20 11:28:04.221 49351 TRACE nova.api.openstack.wsgi TypeError: strptime() argument 1 must be string, not None
2014-03-20 11:28:04.221 49351 TRACE nova.api.openstack.wsgi
2014-03-20 11:28:04.226 49351 INFO nova.osapi_compute.wsgi.server [req-09d455d6-c963-4729-b1b6-082bd04cfe8b 0 b38c2504810f437883a5b57a8b13fe7f] 9.41.223.193,127.0.0.1 "GET /v2/b38c2504810f437883a5b57a8b13fe7f/os-simple-tenant-usage HTTP/1.1" status: 400 len: 362 time: 0.0551372

Revision history for this message
Matt Riedemann (mriedem) wrote :

What does the call look like? How are you using it?

Changed in nova:
status: New → Incomplete
tags: added: api
Revision history for this message
Lauren Taylor (lmtaylor) wrote :

If we use the nova --insecure usage, it would provide start and end time. However, if we do the REST call without it, it would pass None for strptime.

2014-03-21 09:47:21.318 125022 INFO nova.osapi_compute.wsgi.server [req-2cb02b92-2178-48d0-b342-1860019f5fa7 0 63cc19d756414942830a7e7f50accc2d] 9.5.126.244,127.0.0.1 "GET /v2/63cc19d756414942830a7e7f50accc2d/os-simple-tenant-usage/63cc19d756414942830a7e7f50accc2d?start=2014-02-21T13:47:20.824060&end=2014-03-22T13:47:20.824060 HTTP/1.1" status: 200 len: 862 time: 0.4792230

Revision history for this message
Matt Riedemann (mriedem) wrote :

--insecure doesn't have anything to do with you not passing start/end arguments, which are required for the API call:

http://api.openstack.org/api-ref-compute-v2-ext.html

The novaclient allows start/end to be optional because it will default start to be 4 weeks ago and end to be tomorrow (now + 1 day). So I'd say this is a usage error.

Changed in nova:
status: Incomplete → Invalid
Revision history for this message
Lauren Taylor (lmtaylor) wrote :

This is now a logging issue. The REST os-simple-tenant-usage returns a response code 400 which is correct. However, a trace shouldn't be in the log when not all the requirements are being passed.

summary: - os-simple-tenant-usage is returning with the response code 400
+ os-simple-tenant-usage: printing trace in logs if not passing all
+ requirements
Changed in nova:
status: Invalid → New
Changed in nova:
assignee: nobody → Christopher Yeoh (cyeoh-0)
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/85937

Changed in nova:
status: New → In Progress
Revision history for this message
OpenStack Infra (hudson-openstack) wrote :

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

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to nova (master)

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

commit f60c72fac04a97b321a7f2bd0865c1ae81250882
Author: Christopher Yeoh <email address hidden>
Date: Tue Apr 8 14:52:59 2014 +0930

    Avoid traceback logs from simple tenant usage extension

    Avoid generating traceback logs when invalid formatted datetime
    parameters are passed to the simple tenant usage
    extension. Exceptions have not been correctly handled by the
    os-simple-tenant usage extension which results in tracebacks
    being output to the log files. This patch correctly handles
    exceptions as a result of badly formatted datetime strings.

    Change-Id: Iecd42239357b96450b6530c0486b27c68995c37f
    Partial-Bug: 1300972

Matt Riedemann (mriedem)
tags: added: icehouse-backport-potential
Changed in nova:
importance: Undecided → Medium
Revision history for this message
OpenStack Infra (hudson-openstack) wrote :

Reviewed: https://review.openstack.org/85938
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=99e6ec9131c2e3eeb5fe3e1a4dc5a26e6302ebd2
Submitter: Jenkins
Branch: master

commit 99e6ec9131c2e3eeb5fe3e1a4dc5a26e6302ebd2
Author: Christopher Yeoh <email address hidden>
Date: Tue Apr 8 16:08:56 2014 +0930

    Fix _parse_datetime in simple tenant usage extension

    _parse_datetime in os-simple-tenant-usage incorrectly attempts
    to parse the datetime string even when it is None. As a result
    a 400 BadRequest is returned. This has the overall effect of making
    the start and end datetime parameters compulsory when they are meant
    to be optional.

    Note that this restores the behavior where start/end are optional which is
    in contradiction to the API docs, but is the long standing API behaviour.
    This was an API change which was accidentally applied in commit
    I8e0e870727d687da165c809ffb7a4456bff81122 as part of some nova internal
    changes but not picked up by the unitests

    Change-Id: I00427379dc7aa39770f9a16ff026addb6e311735
    Closes-Bug: 1300972

Changed in nova:
status: In Progress → Fix Committed
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to nova (stable/icehouse)

Fix proposed to branch: stable/icehouse
Review: https://review.openstack.org/111802

Revision history for this message
OpenStack Infra (hudson-openstack) wrote :

Fix proposed to branch: stable/icehouse
Review: https://review.openstack.org/111803

Thierry Carrez (ttx)
Changed in nova:
milestone: none → juno-3
status: Fix Committed → Fix Released
Alan Pevec (apevec)
tags: removed: icehouse-backport-potential
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to nova (stable/icehouse)

Reviewed: https://review.openstack.org/111802
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=073ee0697f951e12587e9bd05ce610474027fc4d
Submitter: Jenkins
Branch: stable/icehouse

commit 073ee0697f951e12587e9bd05ce610474027fc4d
Author: Christopher Yeoh <email address hidden>
Date: Tue Apr 8 14:52:59 2014 +0930

    Avoid traceback logs from simple tenant usage extension

    Avoid generating traceback logs when invalid formatted datetime
    parameters are passed to the simple tenant usage
    extension. Exceptions have not been correctly handled by the
    os-simple-tenant usage extension which results in tracebacks
    being output to the log files. This patch correctly handles
    exceptions as a result of badly formatted datetime strings.

    Conflicts:
            nova/tests/api/openstack/compute/contrib/test_simple_tenant_usage.py

    Change-Id: Iecd42239357b96450b6530c0486b27c68995c37f
    Partial-Bug: 1300972
    (cherry picked from commit f60c72fac04a97b321a7f2bd0865c1ae81250882)

tags: added: in-stable-icehouse
Revision history for this message
OpenStack Infra (hudson-openstack) wrote :

Reviewed: https://review.openstack.org/111803
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=825cfe4ab2696612a832e6a90e7ae69816fb7e28
Submitter: Jenkins
Branch: stable/icehouse

commit 825cfe4ab2696612a832e6a90e7ae69816fb7e28
Author: Christopher Yeoh <email address hidden>
Date: Tue Apr 8 16:08:56 2014 +0930

    Fix _parse_datetime in simple tenant usage extension

    _parse_datetime in os-simple-tenant-usage incorrectly attempts
    to parse the datetime string even when it is None. As a result
    a 400 BadRequest is returned. This has the overall effect of making
    the start and end datetime parameters compulsory when they are meant
    to be optional.

    Note that this restores the behavior where start/end are optional which is
    in contradiction to the API docs, but is the long standing API behaviour.
    This was an API change which was accidentally applied in commit
    I8e0e870727d687da165c809ffb7a4456bff81122 as part of some nova internal
    changes but not picked up by the unitests

    Change-Id: I00427379dc7aa39770f9a16ff026addb6e311735
    Closes-Bug: 1300972
    (cherry picked from commit 99e6ec9131c2e3eeb5fe3e1a4dc5a26e6302ebd2)

Thierry Carrez (ttx)
Changed in nova:
milestone: juno-3 → 2014.2
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.