SQLAlchemy error when Generic driver fails to provision a share server

Bug #1813095 reported by Goutham Pacha Ravi on 2019-01-24
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Manila
Medium
Unassigned

Bug Description

Steps to reproduce:

1) Configure the Generic driver in DevStack. Sample configuration file: https://docs.openstack.org/manila/latest/_downloads/3a3628f1f6148dc7984f8e39fda28b80/generic_local.conf (https://docs.openstack.org/manila/latest/contributor/development-environment-devstack.html#dhss-true-driver-handles-share-servers-true-mode)

We need a configuration error so that we can reproduce this failure, so let's fake one:
2) Edit manila.conf, set storage_availability_zone to "xyzzy" (the default value should be "nova")
3) Restart manila services
4) Attempt to create a new share in the xyzzy zone (With manila client shell: $ manila create nfs 1 --availability-zone xyzzy)
5) The share status should be set to "ERROR" in a bit, check the m-share log for this traceback:

ERROR oslo_db.sqlalchemy.exc_filters [None req-2cfb399f-d5b5-4107-802f-773a96296a91 None None] DBAPIError exception wrapped from (psycopg2.IntegrityError) null value in column "value" violates not-null constraint
DETAIL: Failing row contains (2019-01-23 19:51:29.505686, null, null, False, 25, c25934f8-2a79-4fe4-930c-36e4e2a46c4e, subnet_id, null).
 [SQL: 'INSERT INTO share_server_backend_details (created_at, updated_at, deleted_at, deleted, key, value, share_server_id) VALUES (%(created_at)s, %(updated_at)s, %(deleted_at)s, %(deleted)s, %(key)s, %(value)s, %(share_server_id)s) RETURNING share_server_backend_details.id'] [parameters: {'deleted': 'False', 'created_at': datetime.datetime(2019, 1, 23, 19, 51, 29, 505686), 'updated_at': None, 'value': None, 'share_server_id': 'c25934f8-2a79-4fe4-930c-36e4e2a46c4e', 'key': 'subnet_id', 'deleted_at': None}] (Background on this error at: http://sqlalche.me/e/gkpj): IntegrityError: null value in column "value" violates not-null constraint
DETAIL: Failing row contains (2019-01-23 19:51:29.505686, null, null, False, 25, c25934f8-2a79-4fe4-930c-36e4e2a46c4e, subnet_id, null).
ERROR oslo_db.sqlalchemy.exc_filters Traceback (most recent call last):
ERROR oslo_db.sqlalchemy.exc_filters File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1230, in _execute_context
ERROR oslo_db.sqlalchemy.exc_filters cursor, statement, parameters, context
ERROR oslo_db.sqlalchemy.exc_filters File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 536, in do_execute
ERROR oslo_db.sqlalchemy.exc_filters cursor.execute(statement, parameters)
ERROR oslo_db.sqlalchemy.exc_filters IntegrityError: null value in column "value" violates not-null constraint
ERROR oslo_db.sqlalchemy.exc_filters DETAIL: Failing row contains (2019-01-23 19:51:29.505686, null, null, False, 25, c25934f8-2a79-4fe4-930c-36e4e2a46c4e, subnet_id, null).
ERROR oslo_db.sqlalchemy.exc_filters
ERROR oslo_db.sqlalchemy.exc_filters
ERROR oslo_db.sqlalchemy.exc_filters [None req-2cfb399f-d5b5-4107-802f-773a96296a91 None None] DBAPIError exception wrapped from (psycopg2.IntegrityError) null value in column "value" violates not-null constraint
DETAIL: Failing row contains (2019-01-23 19:51:29.531112, null, null, False, 26, c25934f8-2a79-4fe4-930c-36e4e2a46c4e, router_id, null).
 [SQL: 'INSERT INTO share_server_backend_details (created_at, updated_at, deleted_at, deleted, key, value, share_server_id) VALUES (%(created_at)s, %(updated_at)s, %(deleted_at)s, %(deleted)s, %(key)s, %(value)s, %(share_server_id)s) RETURNING share_server_backend_details.id'] [parameters: {'deleted': 'False', 'created_at': datetime.datetime(2019, 1, 23, 19, 51, 29, 531112), 'updated_at': None, 'value': None, 'share_server_id': 'c25934f8-2a79-4fe4-930c-36e4e2a46c4e', 'key': 'router_id', 'deleted_at': None}] (Background on this error at: http://sqlalche.me/e/gkpj): IntegrityError: null value in column "value" violates not-null constraint
DETAIL: Failing row contains (2019-01-23 19:51:29.531112, null, null, False, 26, c25934f8-2a79-4fe4-930c-36e4e2a46c4e, router_id, null).
ERROR oslo_db.sqlalchemy.exc_filters Traceback (most recent call last):
ERROR oslo_db.sqlalchemy.exc_filters File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1230, in _execute_context
ERROR oslo_db.sqlalchemy.exc_filters cursor, statement, parameters, context
ERROR oslo_db.sqlalchemy.exc_filters File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 536, in do_execute
ERROR oslo_db.sqlalchemy.exc_filters cursor.execute(statement, parameters)
ERROR oslo_db.sqlalchemy.exc_filters IntegrityError: null value in column "value" violates not-null constraint
ERROR oslo_db.sqlalchemy.exc_filters DETAIL: Failing row contains (2019-01-23 19:51:29.531112, null, null, False, 26, c25934f8-2a79-4fe4-930c-36e4e2a46c4e, router_id, null).
ERROR oslo_db.sqlalchemy.exc_filters
ERROR oslo_db.sqlalchemy.exc_filters
DEBUG oslo_concurrency.lockutils [None req-19a7058d-0156-4151-84f7-a3ec80d5b290 None None] Lock "instantiate_neutron_api_neutron_net_helper" acquired by "manila.share.drivers.service_instance.neutron_api" :: waited 0.000s {{(pid=1046) inner /usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:327}}
DEBUG oslo_concurrency.lockutils [None req-19a7058d-0156-4151-84f7-a3ec80d5b290 None None] Lock "instantiate_neutron_api_neutron_net_helper" released by "manila.share.drivers.service_instance.neutron_api" :: held 0.001s {{(pid=1046) inner /usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:339}}
DEBUG manila.share.manager [None req-2cfb399f-d5b5-4107-802f-773a96296a91 None None] Following server details cannot be written to db : subnet_id: None
router_id: None {{(pid=1046) _setup_server /opt/stack/new/manila/manila/share/manager.py:3509}}
DEBUG oslo_concurrency.lockutils [None req-19a7058d-0156-4151-84f7-a3ec80d5b290 None None] Lock "instantiate_neutron_api_neutron_net_helper" acquired by "manila.share.drivers.service_instance.neutron_api" :: waited 0.000s {{(pid=1046) inner /usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:327}}
DEBUG oslo_concurrency.lockutils [None req-19a7058d-0156-4151-84f7-a3ec80d5b290 None None] Lock "instantiate_neutron_api_neutron_net_helper" released by "manila.share.drivers.service_instance.neutron_api" :: held 0.000s {{(pid=1046) inner /usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:339}}
DEBUG oslo_concurrency.lockutils [None req-2cfb399f-d5b5-4107-802f-773a96296a91 None None] Lock "share_manager_152ce55f-5937-430e-a195-571cdaa2b4c0" released by "manila.share.manager._wrapped_provide_share_server_for_share" :: held 7.538s {{(pid=1046) inner /usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:339}}
ERROR manila.share.manager [None req-2cfb399f-d5b5-4107-802f-773a96296a91 None None] Creation of share instance 5b5b4372-ab90-49c6-88fe-5cdee2d61f3c failed: failed to get share server.: BadRequest: The requested availability zone is not available (HTTP 400) (Request-ID: req-496cbe8a-8af1-463c-a842-d150e5505680)
INFO manila.message.api [None req-2cfb399f-d5b5-4107-802f-773a96296a91 None None] Creating message record for request_id = req-2cfb399f-d5b5-4107-802f-773a96296a91
ERROR oslo_messaging.rpc.server [None req-2cfb399f-d5b5-4107-802f-773a96296a91 None None] Exception during message handling: BadRequest: The requested availability zone is not available (HTTP 400) (Request-ID: req-496cbe8a-8af1-463c-a842-d150e5505680)
ERROR oslo_messaging.rpc.server Traceback (most recent call last):
ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/server.py", line 166, in _process_incoming
ERROR oslo_messaging.rpc.server res = self.dispatcher.dispatch(message)
ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 265, in dispatch
ERROR oslo_messaging.rpc.server return self._do_dispatch(endpoint, method, ctxt, args)
ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 194, in _do_dispatch
ERROR oslo_messaging.rpc.server result = func(ctxt, **new_args)
ERROR oslo_messaging.rpc.server File "/opt/stack/new/manila/manila/share/manager.py", line 187, in wrapped
ERROR oslo_messaging.rpc.server return f(self, *args, **kwargs)
ERROR oslo_messaging.rpc.server File "/opt/stack/new/manila/manila/utils.py", line 569, in wrapper
ERROR oslo_messaging.rpc.server return func(self, *args, **kwargs)
ERROR oslo_messaging.rpc.server File "/opt/stack/new/manila/manila/share/manager.py", line 1724, in create_share_instance
ERROR oslo_messaging.rpc.server detail=message_field.Detail.NO_SHARE_SERVER)
ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
ERROR oslo_messaging.rpc.server self.force_reraise()
ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
ERROR oslo_messaging.rpc.server File "/opt/stack/new/manila/manila/share/manager.py", line 1706, in create_share_instance
ERROR oslo_messaging.rpc.server share_group=share_group_ref,
ERROR oslo_messaging.rpc.server File "/opt/stack/new/manila/manila/share/manager.py", line 626, in _provide_share_server_for_share
ERROR oslo_messaging.rpc.server return _wrapped_provide_share_server_for_share()
ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py", line 328, in inner
ERROR oslo_messaging.rpc.server return f(*args, **kwargs)
ERROR oslo_messaging.rpc.server File "/opt/stack/new/manila/manila/share/manager.py", line 622, in _wrapped_provide_share_server_for_share
ERROR oslo_messaging.rpc.server metadata=metadata))
ERROR oslo_messaging.rpc.server File "/opt/stack/new/manila/manila/share/manager.py", line 638, in _create_share_server_in_backend
ERROR oslo_messaging.rpc.server metadata=metadata)
ERROR oslo_messaging.rpc.server File "/opt/stack/new/manila/manila/share/manager.py", line 3519, in _setup_server
ERROR oslo_messaging.rpc.server self.driver.deallocate_network(context, share_server['id'])
ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
ERROR oslo_messaging.rpc.server self.force_reraise()
ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
ERROR oslo_messaging.rpc.server File "/opt/stack/new/manila/manila/share/manager.py", line 3470, in _setup_server
ERROR oslo_messaging.rpc.server network_info, metadata=metadata)
ERROR oslo_messaging.rpc.server File "/opt/stack/new/manila/manila/share/driver.py", line 903, in setup_server
ERROR oslo_messaging.rpc.server return self._setup_server(*args, **kwargs)
ERROR oslo_messaging.rpc.server File "/opt/stack/new/manila/manila/share/drivers/generic.py", line 897, in _setup_server
ERROR oslo_messaging.rpc.server self.admin_context, network_info)
ERROR oslo_messaging.rpc.server File "/opt/stack/new/manila/manila/share/drivers/service_instance.py", line 439, in set_up_service_instance
ERROR oslo_messaging.rpc.server context, instance_name, network_info)
ERROR oslo_messaging.rpc.server File "/opt/stack/new/manila/manila/share/drivers/service_instance.py", line 571, in _create_service_instance
ERROR oslo_messaging.rpc.server **create_kwargs)
ERROR oslo_messaging.rpc.server File "/opt/stack/new/manila/manila/compute/nova.py", line 157, in server_create
ERROR oslo_messaging.rpc.server meta=meta)
ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/novaclient/v2/servers.py", line 1335, in create
ERROR oslo_messaging.rpc.server return self._boot(response_key, *boot_args, **boot_kwargs)
ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/novaclient/v2/servers.py", line 776, in _boot
ERROR oslo_messaging.rpc.server return_raw=return_raw, **kwargs)
ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/novaclient/base.py", line 363, in _create
ERROR oslo_messaging.rpc.server resp, body = self.api.client.post(url, body=body)
ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/keystoneauth1/adapter.py", line 357, in post
ERROR oslo_messaging.rpc.server return self.request(url, 'POST', **kwargs)
ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/novaclient/client.py", line 83, in request
ERROR oslo_messaging.rpc.server raise exceptions.from_response(resp, body, url, method)
ERROR oslo_messaging.rpc.server BadRequest: The requested availability zone is not available (HTTP 400) (Request-ID: req-496cbe8a-8af1-463c-a842-d150e5505680)
ERROR oslo_messaging.rpc.server
DEBUG oslo_concurrency.lockutils [None req-19a7058d-0156-4151-84f7-a3ec80d5b290 None None] Lock "service_instance_get_all_service_subnets" released by "manila.share.drivers.service_instance._get_all_service_subnets" :: held 0.265s {{(pid=1046) inner /usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:339}}

Goutham Pacha Ravi (gouthamr) wrote :

The fix for this bug is to prevent updating the database with NULL values

tags: added: low-hanging-fruit
tags: added: generic
Changed in manila:
importance: Undecided → Low
importance: Low → Medium
Varsha Verma (verma-varsha) wrote :

Hi! I intend to apply for Outreachy Summer 2019 and would like to work on this issue as my first contribution.

Changed in manila:
assignee: nobody → Varsha Verma (verma-varsha)
Tom Barron (tpb) wrote :

Varsha - thanks for picking this one up!

Varsha Verma (verma-varsha) wrote :

Hi!
Which file does manila.conf refer to and where can I find it?
Also what should be the expected behavior after introducing the error in the conf file?

Varsha Verma (verma-varsha) wrote :

I found out the location of the file and made the said changes. I wanted to know how do we restart the manila services after that?

Tom Barron (tpb) wrote :

As we discussed on irc but for the record here one uses 'sudo systemctl restart devstack@m-shr' to restart the share service.

LIU Yulong (dragon889) wrote :
Download full text (8.6 KiB)

We meet same error, manila-6.0.1 with Generic driver.
Share server never get created succesfully.

+--------------------------------------+--------+------+-------------+--------+-----------+--------------------+-----------------------------------------+-------------------+
| ID | Name | Size | Share Proto | Status | Is Public | Share Type Name | Host | Availability Zone |
+--------------------------------------+--------+------+-------------+--------+-----------+--------------------+-----------------------------------------+-------------------+
| 68f90beb-5222-4e03-a9db-2f28cb811984 | share1 | 1 | NFS | error | False | default_share_type | xxxxxxxxxxxxxxxxxxxxxxx@generic#GENERIC | nova |
+--------------------------------------+--------+------+-------------+--------+-----------+--------------------+-----------------------------------------+-------------------+

2019-06-14 14:15:21.469 5830 ERROR oslo_db.sqlalchemy.exc_filters [req-5907456c-ebf7-4895-9e48-613943ec7a98 7f25360ba6bb4480b2ab153da41e6a5d 504bf34e67784e258981a782add8e995 - - -] DBAPIError exception wrapped from (pymysql.err.IntegrityError) (1048, u"Column 'value' cannot be null") [SQL: u'INSERT INTO share_server_backend_details (created_at, updated_at, deleted_at, deleted, `key`, value, share_server_id) VALUES (%(created_at)s, %(updated_at)s, %(deleted_at)s, %(deleted)s, %(key)s, %(value)s, %(share_server_id)s)'] [parameters: {'deleted': 'False', 'created_at': datetime.datetime(2019, 6, 14, 6, 15, 21, 468474), 'updated_at': None, 'value': None, 'share_server_id': '3f8054a5-0ce4-4e0b-9108-9f1295c4bf68', 'key': 'subnet_id', 'deleted_at': None}] (Background on this error at: http://sqlalche.me/e/gkpj): IntegrityError: (1048, u"Column 'value' cannot be null")
2019-06-14 14:15:21.469 5830 ERROR oslo_db.sqlalchemy.exc_filters Traceback (most recent call last):
2019-06-14 14:15:21.469 5830 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1193, in _execute_context
2019-06-14 14:15:21.469 5830 ERROR oslo_db.sqlalchemy.exc_filters context)
2019-06-14 14:15:21.469 5830 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/default.py", line 507, in do_execute
2019-06-14 14:15:21.469 5830 ERROR oslo_db.sqlalchemy.exc_filters cursor.execute(statement, parameters)
2019-06-14 14:15:21.469 5830 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 170, in execute
2019-06-14 14:15:21.469 5830 ERROR oslo_db.sqlalchemy.exc_filters result = self._query(query)
2019-06-14 14:15:21.469 5830 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib/python2.7/site-packages/pymysql/cursors.py", line 328, in _query
2019-06-14 14:15:21.469 5830 ERROR oslo_db.sqlalchemy.exc_filters conn.query(q)
2019-06-14 14:15:21.469 5830 ERROR oslo_db.sqlalchemy.exc_filters File "/usr/lib/python2.7/site-packages/pymysql/connections.py", line 516, in query
2019-06-14 14:15:21.469 5830 ERROR oslo_db.sqlalchemy.exc_filters self._affected_rows = self._read_...

Read more...

Changed in manila:
assignee: Varsha Verma (verma-varsha) → nobody
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers