Creating metering-label-rule with non-existent UUID of metering_label_id raised 500 Internal Server Error

[Rahmad Ade Putra]

1. When I was trying to create metering-label-rule by inserting non-existent UUID of metering_label_id then it raised 500 Internal Server Error, and according to the traceback of logs itself which explained that "foreign key constraint". However this perhaps should be 404 Not Found since I was inserting non-existent UUID of metering_label_id.

Here I attached all of request which was sent to API and traceback log.

-------
Request parameters

curl -g -i -X POST http://192.168.122.139:9696/v2.0/metering/metering-label-rules -H "X-Auth-Token: $TOKEN" -d '{"metering_label_rule":{"remote_ip_prefix":"10.0.1.0/24", "direction": "ingress", "metering_label_id":"0fd2758c-0754-4773-997f-44d3db288a75"}}'
HTTP/1.1 500 Internal Server Error
Content-Type: application/json
Content-Length: 150
X-Openstack-Request-Id: req-f4e2ae59-4d4b-491f-96be-58d9ce6ebc39
Date: Fri, 29 Jul 2016 01:35:24 GMT

{"NeutronError": {"message": "Request Failed: internal server error while processing your request.", "type": "HTTPInternalServerError", "detail": ""}}

--------
Log

2016-07-29 10:35:24.047 1448 DEBUG neutron.wsgi [-] (1448) accepted ('192.168.122.139', 6574) server /usr/local/lib/python2.7/dist-packages/eventlet/wsgi.py:868
2016-07-29 10:35:24.149 1448 DEBUG neutron.api.v2.base [req-f4e2ae59-4d4b-491f-96be-58d9ce6ebc39 e01bc3eadeb045edb02fc6b2af4b5d49 867929bfedca4a719e17a7f3293845de - - -] Request body: {u'metering_label_rule': {u'remote_ip_prefix': u'10.0.1.0/24', u'direction': u'ingress', u'metering_label_id': u'0fd2758c-0754-4773-997f-44d3db288a75'}} prepare_request_body /opt/stack/neutron/neutron/api/v2/base.py:649
2016-07-29 10:35:24.152 1448 DEBUG neutron.api.v2.base [req-f4e2ae59-4d4b-491f-96be-58d9ce6ebc39 e01bc3eadeb045edb02fc6b2af4b5d49 867929bfedca4a719e17a7f3293845de - - -] Unknown quota resources ['metering_label_rule']. _create /opt/stack/neutron/neutron/api/v2/base.py:445
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource [req-f4e2ae59-4d4b-491f-96be-58d9ce6ebc39 e01bc3eadeb045edb02fc6b2af4b5d49 867929bfedca4a719e17a7f3293845de - - -] create failed: No details.
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource Traceback (most recent call last):
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/opt/stack/neutron/neutron/api/v2/resource.py", line 79, in resource
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource result = method(request=request, **args)
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/opt/stack/neutron/neutron/api/v2/base.py", line 397, in create
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource return self._create(request, body, **kwargs)
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/oslo_db/api.py", line 148, in wrapper
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource ectxt.value = e.inner_exc
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource self.force_reraise()
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource six.reraise(self.type_, self.value, self.tb)
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/oslo_db/api.py", line 138, in wrapper
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource return f(*args, **kwargs)
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/opt/stack/neutron/neutron/api/v2/base.py", line 510, in _create
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource obj = do_create(body)
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/opt/stack/neutron/neutron/api/v2/base.py", line 492, in do_create
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource request.context, reservation.reservation_id)
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource self.force_reraise()
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource six.reraise(self.type_, self.value, self.tb)
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/opt/stack/neutron/neutron/api/v2/base.py", line 485, in do_create
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource return obj_creator(request.context, **kwargs)
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/opt/stack/neutron/neutron/services/metering/metering_plugin.py", line 63, in create_metering_label_rule
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource context, metering_label_rule)
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/opt/stack/neutron/neutron/db/metering/metering_db.py", line 174, in create_metering_label_rule
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource context.session.add(metering_db)
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 490, in __exit__
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource self.rollback()
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 60, in __exit__
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource compat.reraise(exc_type, exc_value, exc_tb)
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 487, in __exit__
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource self.commit()
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 392, in commit
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource self._prepare_impl()
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 372, in _prepare_impl
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource self.session.flush()
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2019, in flush
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource self._flush(objects)
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2137, in _flush
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource transaction.rollback(_capture_exception=True)
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 60, in __exit__
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource compat.reraise(exc_type, exc_value, exc_tb)
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2101, in _flush
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource flush_context.execute()
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 373, in execute
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource rec.execute(self)
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 532, in execute
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource uow
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 174, in save_obj
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource mapper, table, insert)
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 767, in _emit_insert_statements
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource execute(statement, multiparams)
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 914, in execute
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource return meth(self, multiparams, params)
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/sql/elements.py", line 323, in _execute_on_connection
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource return connection._execute_clauseelement(self, multiparams, params)
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1010, in _execute_clauseelement
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource compiled_sql, distilled_params
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1146, in _execute_context
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource context)
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1337, in _handle_dbapi_exception
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource util.raise_from_cause(newraise, exc_info)
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 202, in raise_from_cause
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource reraise(type(exception), exception, tb=exc_tb, cause=cause)
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1139, in _execute_context
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource context)
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 450, in do_execute
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource cursor.execute(statement, parameters)
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/pymysql/cursors.py", line 161, in execute
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource result = self._query(query)
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/pymysql/cursors.py", line 317, in _query
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource conn.query(q)
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 837, in query
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource self._affected_rows = self._read_query_result(unbuffered=unbuffered)
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 1021, in _read_query_result
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource result.read()
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 1304, in read
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource first_packet = self.connection._read_packet()
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 983, in _read_packet
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource packet.check_error()
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 395, in check_error
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource err.raise_mysql_exception(self._data)
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/pymysql/err.py", line 120, in raise_mysql_exception
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource _check_mysql_exception(errinfo)
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource File "/usr/local/lib/python2.7/dist-packages/pymysql/err.py", line 112, in _check_mysql_exception
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource raise errorclass(errno, errorvalue)
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource DBReferenceError: (pymysql.err.IntegrityError) (1452, u'Cannot add or update a child row: a foreign key constraint fails (`neutron`.`meteringlabelrules`, CONSTRAINT `meteringlabelrules_ibfk_1` FOREIGN KEY (`metering_label_id`) REFERENCES `meteringlabels` (`id`) ON DELETE CASCADE)') [SQL: u'INSERT INTO meteringlabelrules (id, direction, remote_ip_prefix, metering_label_id, excluded) VALUES (%(id)s, %(direction)s, %(remote_ip_prefix)s, %(metering_label_id)s, %(excluded)s)'] [parameters: {'remote_ip_prefix': u'10.0.1.0/24', 'direction': u'ingress', 'metering_label_id': u'0fd2758c-0754-4773-997f-44d3db288a75', 'id': 'e57b01bc-59fa-4d44-a4dc-1a11c7fc3582', 'excluded': 0}]
2016-07-29 10:35:24.186 1448 ERROR neutron.api.v2.resource
2016-07-29 10:35:24.191 1448 INFO neutron.wsgi [req-f4e2ae59-4d4b-491f-96be-58d9ce6ebc39 e01bc3eadeb045edb02fc6b2af4b5d49 867929bfedca4a719e17a7f3293845de - - -] 192.168.122.139 - - [29/Jul/2016 10:35:24] "POST /v2.0/metering/metering-label-rules HTTP/1.1" 500 344 0.139746

[Victor Morales (electrocucaracha)]

If I try to create it from python-neutron client. It seems to validate the labels before to proceed with the creation.

$ neutron meter-label-rule-create e973c8fd200a4eeb9b119545ab21da26 192.168.50.0/24

...
DEBUG: keystoneauth.identity.v2 Making authentication request to http://10.0.2.15/identity/v2.0/tokens
DEBUG: keystoneauth.session REQ: curl -g -i -X GET http://10.0.2.15:9696/v2.0/metering/metering-labels.json?fields=id&name=e973c8fd200a4eeb9b119545ab21da26 -H "User-Agent: python-neutronclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}f...8"
...

Resulting a error message 'NotFound: Unable to find metering_label with name or id 'e973c8fd200a4eeb9b119545ab21da26'. IMHO, this validation needs to be moved from the client to the server.

[Victor Morales (electrocucaracha)]

Can you provide more information about the enviroment/release that you're using? I'm getting the follow message:

$ curl -vvv -g -i -X POST http://10.0.2.15:9696/v2.0/metering/metering-label-rules -H "X-Auth-Token: aa5b350a289648518dd06296242661ce" -d '{"metering_label_rule":{"remote_ip_prefix":"10.0.1.0/24", "direction": "ingress", "metering_label_id":"0fd2758c-0754-4773-997f-44d3db288a75"}}'
* Hostname was NOT found in DNS cache
* Trying 10.0.2.15...
* Connected to 10.0.2.15 (10.0.2.15) port 9696 (#0)
> POST /v2.0/metering/metering-label-rules HTTP/1.1
> User-Agent: curl/7.35.0
> Host: 10.0.2.15:9696
> Accept: */*
> X-Auth-Token: aa5b350a289648518dd06296242661ce
> Content-Length: 142
> Content-Type: application/x-www-form-urlencoded
>
* upload completely sent off: 142 out of 142 bytes
< HTTP/1.1 404 Not Found
HTTP/1.1 404 Not Found
< Content-Length: 52
Content-Length: 52
< Content-Type: text/plain; charset=UTF-8
Content-Type: text/plain; charset=UTF-8
< X-Openstack-Request-Id: req-3b0a60c0-4a16-4c95-b03e-0fcf803e7089
X-Openstack-Request-Id: req-3b0a60c0-4a16-4c95-b03e-0fcf803e7089
< Date: Mon, 01 Aug 2016 22:48:43 GMT
Date: Mon, 01 Aug 2016 22:48:43 GMT

<
404 Not Found

The resource could not be found.

* Connection #0 to host 10.0.2.15 left intact

[Kengo Hobo (hobo-kengo)]

Hi Victor,

I tried to request in master and the 500 error is returned.
============
ubuntu@neutron-ml2:~/openstack/devstack$ curl -si -X POST -H "Content-type: application/json" http://172.16.1.29:9696/v2.0/metering/metering-label-rules -H "X-AUTH-TOKEN:${TOKEN}" -d '{"metering_label_rule":{"metering_label_id":"5201d961-9296-4e9d-b896-ae421047e759", "direction":"ingress", "remote_ip_prefix":"10.10.10.10/32"}}'
HTTP/1.1 500 Internal Server Error
Content-Type: application/json
Content-Length: 150
X-Openstack-Request-Id: req-be86d8fa-c1d0-473b-a4c4-9029f7507caa
Date: Tue, 02 Aug 2016 03:05:37 GMT

{"NeutronError": {"message": "Request Failed: internal server error while processing your request.", "type": "HTTPInternalServerError", "detail": ""}}
====================

Did you add 'metering' to service_plugiuns in neutron.conf?
I tried to request without adding 'metering' to service_plugins.
===============
ubuntu@neutron-ml2:~/openstack/devstack$ curl -si -X POST -H "Content-type: application/json" http://172.16.1.29:9696/v2.0/metering/metering-label-rules -H "X-AUTH-TOKEN:${TOKEN}" -d '{"metering_label_rule":{"metering_label_id":"5201d961-9296-4e9d-b896-ae421047e759", "direction":"ingress", "remote_ip_prefix":"10.10.10.10/32"}}'
HTTP/1.1 404 Not Found
Content-Length: 52
Content-Type: text/plain; charset=UTF-8
X-Openstack-Request-Id: req-ce9fa30e-c26a-4927-83bd-4f2e17a62f1a
Date: Tue, 02 Aug 2016 03:08:23 GMT

404 Not Found

The resource could not be found.
================

[OpenStack Infra (hudson-openstack)]

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

[Kengo Hobo (hobo-kengo)]

Rahmad is my team member.
We agreed that I take this bug.

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/359591
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=2d33e2d77b096d098c26b0c7dfb5b8104054079c
Submitter: Jenkins
Branch: master

commit 2d33e2d77b096d098c26b0c7dfb5b8104054079c
Author: hobo.kengo <email address hidden>
Date: Wed Aug 24 04:50:23 2016 +0000

    Handle label_id's DBReferenceError when creating label-rule

    Currently, creating meter-label-rule with non-existent meter-label
    is returned with 500 error, because there is no error handling for
    foreign key constraint error from DB.
    This patch adds error handling for the error from DB
    and raises MeteringLabelNotFound error.

    Change-Id: I05d6c70cfe1c54618c55cba435bc8e3301948738
    Closes-Bug: #1608378

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/neutron 10.0.0.0b1 development milestone.

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/422023
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=f1cabc13212a45aaf24e85bbcfb8a0ab11fae004
Submitter: Jenkins
Branch: stable/newton

commit f1cabc13212a45aaf24e85bbcfb8a0ab11fae004
Author: hobo.kengo <email address hidden>
Date: Wed Aug 24 04:50:23 2016 +0000

    Handle label_id's DBReferenceError when creating label-rule

    Currently, creating meter-label-rule with non-existent meter-label
    is returned with 500 error, because there is no error handling for
    foreign key constraint error from DB.
    This patch adds error handling for the error from DB
    and raises MeteringLabelNotFound error.

    Conflicts:
     neutron/db/metering/metering_db.py
     neutron/tests/unit/db/metering/test_metering_db.py

    Change-Id: I05d6c70cfe1c54618c55cba435bc8e3301948738
    Closes-Bug: #1608378
    (cherry picked from commit 2d33e2d77b096d098c26b0c7dfb5b8104054079c)

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/neutron 9.2.0 release.