NetApp cDOT drivers refuse to startup due to issues with performance APIs

Bug #1682668 reported by Goutham Pacha Ravi
8
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Cinder
New
Undecided
Unassigned

Bug Description

How to reproduce:

With a least privileged "cluster" scoped user that can connect to ONTAP 9.1 with ontapi privileges, the driver fails to start up.

The user has been assigned readonly access to "statistics" command directory at the cluster level.

The log below is from stable/newton:

<cinder.volume.drivers.netapp.dataontap.client.api.NaServer object at 0x7fbb8123d9d0>, 'na_element': <system-get-ontapi-version/>
, 'enable_tunneling': False} trace_logging_wrapper /usr/lib/python2.7/site-packages/cinder/utils.py:891
2017-04-13 19:35:30.820 8770 DEBUG cinder.volume.drivers.netapp.dataontap.client.api [req-0e249d15-0883-4239-81ef-2ef5557381a7 - - - - -] <== send_http_request: return (33ms) <results xmlns="http://www.netapp.com/filer/admin" status="passed">
  <major-version>1</major-version>
  <minor-version>110</minor-version>
</results>
 trace_logging_wrapper /usr/lib/python2.7/site-packages/cinder/utils.py:915
2017-04-13 19:35:30.821 8770 DEBUG cinder.volume.drivers.netapp.dataontap.client.client_cmode [req-0e249d15-0883-4239-81ef-2ef5557381a7 - - - - -] <== get_ontapi_version: return (33ms) ('1', '110') trace_logging_wrapper /usr/lib/python2.7/site-packages/cinder/utils.py:915
2017-04-13 19:35:30.822 8770 DEBUG cinder.volume.drivers.netapp.dataontap.client.client_cmode [req-0e249d15-0883-4239-81ef-2ef5557381a7 - - - - -] ==> _init_features: call {'args': (<cinder.volume.drivers.netapp.dataontap.client.client_cmode.Client object at 0x7fbb820d1650>,), 'kwargs': {}} trace_logging_wrapper /usr/lib/python2.7/site-packages/cinder/utils.py:891
2017-04-13 19:35:30.822 8770 DEBUG cinder.volume.drivers.netapp.dataontap.client.client_cmode [req-0e249d15-0883-4239-81ef-2ef5557381a7 - - - - -] ==> _init_features: call {'self': <cinder.volume.drivers.netapp.dataontap.client.client_cmode.Client object at 0x7fbb820d1650>} trace_logging_wrapper /usr/lib/python2.7/site-packages/cinder/utils.py:891
2017-04-13 19:35:30.823 8770 DEBUG cinder.volume.drivers.netapp.dataontap.client.client_cmode [req-0e249d15-0883-4239-81ef-2ef5557381a7 - - - - -] ==> _init_features: call {'self': <cinder.volume.drivers.netapp.dataontap.client.client_cmode.Client object at 0x7fbb820d1650>} trace_logging_wrapper /usr/lib/python2.7/site-packages/cinder/utils.py:891
2017-04-13 19:35:30.824 8770 DEBUG cinder.volume.drivers.netapp.dataontap.client.client_cmode [req-0e249d15-0883-4239-81ef-2ef5557381a7 - - - - -] <== _init_features: return (0ms) None trace_logging_wrapper /usr/lib/python2.7/site-packages/cinder/utils.py:915
2017-04-13 19:35:30.824 8770 DEBUG cinder.volume.drivers.netapp.dataontap.client.client_cmode [req-0e249d15-0883-4239-81ef-2ef5557381a7 - - - - -] ==> get_ontapi_version: call {'cached': True, 'self': <cinder.volume.drivers.netapp.dataontap.client.client_cmode.Client object at 0x7fbb820d1650>} trace_logging_wrapper /usr/lib/python2.7/site-packages/cinder/utils.py:891
2017-04-13 19:35:30.825 8770 DEBUG cinder.volume.drivers.netapp.dataontap.client.client_cmode [req-0e249d15-0883-4239-81ef-2ef5557381a7 - - - - -] <== get_ontapi_version: return (0ms) (1, 110) trace_logging_wrapper /usr/lib/python2.7/site-packages/cinder/utils.py:915
2017-04-13 19:35:30.825 8770 DEBUG cinder.volume.drivers.netapp.dataontap.client.client_cmode [req-0e249d15-0883-4239-81ef-2ef5557381a7 - - - - -] <== _init_features: return (2ms) None trace_logging_wrapper /usr/lib/python2.7/site-packages/cinder/utils.py:915
2017-04-13 19:35:30.825 8770 DEBUG cinder.volume.drivers.netapp.dataontap.client.client_cmode [req-0e249d15-0883-4239-81ef-2ef5557381a7 - - - - -] <== _init_features: return (3ms) None trace_logging_wrapper /usr/lib/python2.7/site-packages/cinder/utils.py:915
2017-04-13 19:35:30.826 8770 DEBUG cinder.volume.drivers.netapp.dataontap.client.client_cmode [req-0e249d15-0883-4239-81ef-2ef5557381a7 - - - - -] <== __init__: return (41ms) None trace_logging_wrapper /usr/lib/python2.7/site-packages/cinder/utils.py:915
2017-04-13 19:35:30.826 8770 DEBUG cinder.volume.drivers.netapp.dataontap.client.client_cmode [req-0e249d15-0883-4239-81ef-2ef5557381a7 - - - - -] <== __init__: return (41ms) None trace_logging_wrapper /usr/lib/python2.7/site-packages/cinder/utils.py:915
2017-04-13 19:35:30.826 8770 DEBUG cinder.volume.drivers.netapp.dataontap.client.client_cmode [req-0e249d15-0883-4239-81ef-2ef5557381a7 - - - - -] ==> get_performance_counter_info: call {'self': <cinder.volume.drivers.netapp.dataontap.client.client_cmode.Client object at 0x7fbb820d1650>, 'counter_name': 'avg_processor_busy', 'object_name': 'system:constituent'} trace_logging_wrapper /usr/lib/python2.7/site-packages/cinder/utils.py:891
2017-04-13 19:35:30.827 8770 DEBUG cinder.volume.drivers.netapp.dataontap.client.client_cmode [req-0e249d15-0883-4239-81ef-2ef5557381a7 - - - - -] ==> send_request: call {'enable_tunneling': False, 'self': <cinder.volume.drivers.netapp.dataontap.client.client_cmode.Client object at 0x7fbb820d1650>, 'api_args': {'objectname': 'system:constituent'}, 'api_name': 'perf-object-counter-list-info'} trace_logging_wrapper /usr/lib/python2.7/site-packages/cinder/utils.py:891
2017-04-13 19:35:30.827 8770 DEBUG cinder.volume.drivers.netapp.dataontap.client.api [req-0e249d15-0883-4239-81ef-2ef5557381a7 - - - - -] ==> send_http_request: call {'self': <cinder.volume.drivers.netapp.dataontap.client.api.NaServer object at 0x7fbb8123d9d0>, 'na_element': <perf-object-counter-list-info>
  <objectname>system:constituent</objectname>
</perf-object-counter-list-info>
, 'enable_tunneling': False} trace_logging_wrapper /usr/lib/python2.7/site-packages/cinder/utils.py:891
2017-04-13 19:35:30.851 8770 DEBUG cinder.volume.drivers.netapp.dataontap.client.api [req-0e249d15-0883-4239-81ef-2ef5557381a7 - - - - -] <== send_http_request: return (23ms) <results xmlns="http://www.netapp.com/filer/admin" status="passed"/>
 trace_logging_wrapper /usr/lib/python2.7/site-packages/cinder/utils.py:915
2017-04-13 19:35:30.851 8770 DEBUG cinder.volume.drivers.netapp.dataontap.client.client_cmode [req-0e249d15-0883-4239-81ef-2ef5557381a7 - - - - -] <== send_request: return (24ms) <results xmlns="http://www.netapp.com/filer/admin" status="passed"/>
 trace_logging_wrapper /usr/lib/python2.7/site-packages/cinder/utils.py:915
2017-04-13 19:35:30.853 8770 DEBUG cinder.volume.drivers.netapp.dataontap.client.client_cmode [req-0e249d15-0883-4239-81ef-2ef5557381a7 - - - - -] <== get_performance_counter_info: exception (25ms) NotFound(u'Counter avg_processor_busy not found',) trace_logging_wrapper /usr/lib/python2.7/site-packages/cinder/utils.py:901
2017-04-13 19:35:30.853 8770 DEBUG cinder.volume.drivers.netapp.dataontap.nfs_cmode [req-0e249d15-0883-4239-81ef-2ef5557381a7 - - - - -] <== do_setup: exception (487ms) NotFound(u'Counter avg_processor_busy not found',) trace_logging_wrapper /usr/lib/python2.7/site-packages/cinder/utils.py:901
2017-04-13 19:35:30.854 8770 DEBUG cinder.volume.drivers.netapp.dataontap.nfs_cmode [req-0e249d15-0883-4239-81ef-2ef5557381a7 - - - - -] <== do_setup: exception (487ms) NotFound(u'Counter avg_processor_busy not found',) trace_logging_wrapper /usr/lib/python2.7/site-packages/cinder/utils.py:901
2017-04-13 19:35:30.854 8770 ERROR cinder.volume.manager [req-0e249d15-0883-4239-81ef-2ef5557381a7 - - - - -] Failed to initialize driver.
2017-04-13 19:35:30.854 8770 ERROR cinder.volume.manager Traceback (most recent call last):
2017-04-13 19:35:30.854 8770 ERROR cinder.volume.manager File "/usr/lib/python2.7/site-packages/cinder/volume/manager.py", line 414, in init_host
2017-04-13 19:35:30.854 8770 ERROR cinder.volume.manager self.driver.do_setup(ctxt)
2017-04-13 19:35:30.854 8770 ERROR cinder.volume.manager File "/usr/lib/python2.7/site-packages/cinder/utils.py", line 841, in trace_method_logging_wrapper
2017-04-13 19:35:30.854 8770 ERROR cinder.volume.manager return trace(f)(*args, **kwargs)
2017-04-13 19:35:30.854 8770 ERROR cinder.volume.manager File "/usr/lib/python2.7/site-packages/cinder/utils.py", line 895, in trace_logging_wrapper
2017-04-13 19:35:30.854 8770 ERROR cinder.volume.manager result = f(*args, **kwargs)
2017-04-13 19:35:30.854 8770 ERROR cinder.volume.manager File "/usr/lib/python2.7/site-packages/cinder/utils.py", line 841, in trace_method_logging_wrapper
2017-04-13 19:35:30.854 8770 ERROR cinder.volume.manager return trace(f)(*args, **kwargs)
2017-04-13 19:35:30.854 8770 ERROR cinder.volume.manager File "/usr/lib/python2.7/site-packages/cinder/utils.py", line 895, in trace_logging_wrapper
2017-04-13 19:35:30.854 8770 ERROR cinder.volume.manager result = f(*args, **kwargs)
2017-04-13 19:35:30.854 8770 ERROR cinder.volume.manager File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/netapp/dataontap/nfs_cmode.py", line 80, in do_setup
2017-04-13 19:35:30.854 8770 ERROR cinder.volume.manager self.zapi_client)
2017-04-13 19:35:30.854 8770 ERROR cinder.volume.manager File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/netapp/dataontap/performance/perf_cmode.py", line 32, in __init__
2017-04-13 19:35:30.854 8770 ERROR cinder.volume.manager super(PerformanceCmodeLibrary, self).__init__(zapi_client)
2017-04-13 19:35:30.854 8770 ERROR cinder.volume.manager File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/netapp/dataontap/performance/perf_base.py", line 34, in __init__
2017-04-13 19:35:30.854 8770 ERROR cinder.volume.manager self._init_counter_info()
2017-04-13 19:35:30.854 8770 ERROR cinder.volume.manager File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/netapp/dataontap/performance/perf_cmode.py", line 47, in _init_counter_info
2017-04-13 19:35:30.854 8770 ERROR cinder.volume.manager 'avg_processor_busy'))
2017-04-13 19:35:30.854 8770 ERROR cinder.volume.manager File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/netapp/dataontap/performance/perf_base.py", line 224, in _get_base_counter_name
2017-04-13 19:35:30.854 8770 ERROR cinder.volume.manager object_name, counter_name)
2017-04-13 19:35:30.854 8770 ERROR cinder.volume.manager File "/usr/lib/python2.7/site-packages/cinder/utils.py", line 841, in trace_method_logging_wrapper
2017-04-13 19:35:30.854 8770 ERROR cinder.volume.manager return trace(f)(*args, **kwargs)
2017-04-13 19:35:30.854 8770 ERROR cinder.volume.manager File "/usr/lib/python2.7/site-packages/cinder/utils.py", line 895, in trace_logging_wrapper
2017-04-13 19:35:30.854 8770 ERROR cinder.volume.manager result = f(*args, **kwargs)
2017-04-13 19:35:30.854 8770 ERROR cinder.volume.manager File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/netapp/dataontap/client/client_base.py", line 314, in get_performance_counter_info
2017-04-13 19:35:30.854 8770 ERROR cinder.volume.manager raise exception.NotFound(_('Counter %s not found') % counter_name)
2017-04-13 19:35:30.854 8770 ERROR cinder.volume.manager NotFound: Counter avg_processor_busy not found
2017-04-13 19:35:30.854 8770 ERROR cinder.volume.manager
2017-04-13 19:35:30.859 8770 DEBUG cinder.service [req-0e249d15-0883-4239-81ef-2ef5557381a7 - - - - -] Creating RPC server for service cinder-volume start /usr/lib/python2.7/site-packages/cinder/service.py:236
2017-04-13 19:35:30.875 8770 DEBUG cinder.service [req-0e249d15-0883-4239-81ef-2ef5557381a7 - - - - -] Pinning object versions for RPC server serializer to 1.11 start /usr/lib/python2.7/site-packages/cinder/service.py:244
2017-04-13 19:35:30.905 8770 INFO cinder.volume.manager [req-0e249d15-0883-4239-81ef-2ef5557381a7 - - - - -] Initializing RPC dependent components of volume driver NetAppCmodeNfsDriver (1.0.0)
2017-04-13 19:35:30.906 8770 ERROR cinder.utils [req-0e249d15-0883-4239-81ef-2ef5557381a7 - - - - -] Volume driver NetAppCmodeNfsDriver not initialized
2017-04-13 19:35:30.907 8770 ERROR cinder.volume.manager [req-0e249d15-0883-4239-81ef-2ef5557381a7 - - - - -] Cannot complete RPC initialization because driver isn't initialized properly.
2017-04-13 19:35:40.913 8770 ERROR cinder.service [-] Manager for service cinder-volume d08-9e-01-90-24-7e@backend-netapp-0 is reporting problems, not sending heartbeat. Service will appear "down".
2017-04-13 19:35:50.920 8770 ERROR cinder.service [-] Manager for service cinder-volume d08-9e-01-90-24-7e@backend-netapp-0 is reporting problems, not sending heartbeat. Service will appear "down".

Two considerations:
* Headroom calculation must be optional, i.e, done if user configured on cinder has access to glean all the information necessary from the ONTAP back end; without headroom calculation, the driver must still be able to perform all necessary cinder interactions.
* Account setup and permissions must be called out for the necessary interactions.

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.