SQLAlchemy error when Generic driver fails to provision a share server

Bug #1813095 reported by Goutham Pacha Ravi
8
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Shared File Systems Service (Manila)
Triaged
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}}

Revision history for this message
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
Revision history for this message
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)
Revision history for this message
Tom Barron (tpb) wrote :

Varsha - thanks for picking this one up!

Revision history for this message
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?

Revision history for this message
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?

Revision history for this message
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.

Revision history for this message
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
Changed in manila:
assignee: nobody → Esther Kisakye (ekisakye)
Vida Haririan (vhariria)
Changed in manila:
status: New → Triaged
Changed in manila:
assignee: Esther Kisakye (ekisakye) → nobody
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.