Bug 1686538

Summary: [Cinderlib] - "Internal Engine Error" appears when creating disk of storage domain for Netapp
Product: [oVirt] ovirt-engine Reporter: Shir Fishbain <sfishbai>
Component: BLL.StorageAssignee: Benny Zlotnik <bzlotnik>
Status: CLOSED NOTABUG QA Contact: Elad <ebenahar>
Severity: high Docs Contact:
Priority: unspecified    
Version: futureCC: aefrat, bugs
Target Milestone: ovirt-4.3.4Flags: pm-rhel: ovirt-4.3+
Target Release: ---   
Hardware: x86_64   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2019-03-18 14:41:11 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: Storage RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1539837    
Attachments:
Description Flags
Logs
none
NetApp free space print screen none

Description Shir Fishbain 2019-03-07 16:13:43 UTC 
Created attachment 1541900 [details]
Logs

Description of problem:
After creating SD of Netapp and trying to create a disk from it, we're getting the following error:
"Error while executing action Add Disk to VM: Internal Engine Error "
After creating a new volume with 10 GB in Netapp the ERROR still appears 

Version-Release number of selected component (if applicable):
cinderlib version 0.3.9
vdsm-4.30.9-1.el7ev.x86_64
ovirt-engine-4.3.1.1-0.1.el7.noarch

How reproducible:
Always

Steps to Reproduce:
1.Create block storage managed domain on a Netapp backend (see REST request in additional info section)
2.Create a disk from the storage domain in step 1 

Actual results:
Failing to create the disk
2019-03-07 17:16:50,966+02 ERROR [org.ovirt.engine.core.common.utils.cinderlib.CinderlibExecutor] (EE-ManagedThreadFactory-commandCoordinator-Thread-5) [dc54241f-75d9-42ad-9c32-b68bc8db8ff9] cinderlib execution 
failed: Traceback (most recent call last):
  File "./cinderlib-client.py", line 137, in main
    args.command(args)
  File "./cinderlib-client.py", line 153, in create_volume
    backend.create_volume(int(args.size), id=args.volume_id)
  File "/usr/lib/python2.7/site-packages/cinderlib/cinderlib.py", line 156, in create_volume
    vol.create()
  File "/usr/lib/python2.7/site-packages/cinderlib/objects.py", line 446, in create
    self._raise_with_resource()
  File "/usr/lib/python2.7/site-packages/cinderlib/objects.py", line 222, in _raise_with_resource
    six.reraise(*exc_info)
  File "/usr/lib/python2.7/site-packages/cinderlib/objects.py", line 439, in create
    model_update = self.backend.driver.create_volume(self._ovo)
  File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/netapp/dataontap/iscsi_cmode.py", line 47, in create_volume
    return self.library.create_volume(volume)
  File "/usr/lib/python2.7/site-packages/cinder/utils.py", line 830, in trace_method_logging_wrapper
    return f(*args, **kwargs)
  File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/netapp/dataontap/block_base.py", line 250, in create_volume
    volume['name']))
VolumeBackendAPIException: Bad or unexpected response from the storage volume backend API: Volume volume-0c81c1e9-4483-465f-b4c1-63882e982338 could not be created.

2019-03-07 17:16:51,034+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-56) [] EVENT_ID: USER_ADD_DISK_FINISHED_FAILURE(2,022), Add-Disk operation failed to complete

Expected results:
Success to create the disk 

Additional info:
<storage_domain>
   <name>cinder-netapp</name>
   <type>managed_block_storage</type>
   <storage>
      <type>managed_block_storage</type>
      <driver_options>
      	<property>
            <name>netapp_server_hostname</name>
            <value>10.46.2.1</value>
         </property>
      	<property>
            <name>netapp_login</name>
            <value>qeadmin</value>
         </property>
         <property>
            <name>netapp_password</name>
            <value>Qum10net</value>
         </property>
         <property>
            <name>volume_driver</name>
            <value>cinder.volume.drivers.netapp.common.NetAppDriver</value>
         </property>
         <property>
            <name>netapp_storage_family</name>
            <value>ontap_cluster</value>
         </property>
         <property>
            <name>netapp_storage_protocol</name>
            <value>iscsi</value>
         </property>
         <property>
            <name>netapp_vserver</name>
            <value>vserver-rhv-qe</value>
         </property>
         <property>
            <name>netapp_server_port</name>
            <value>80</value>
         </property>
         <property>
            <name>netapp_size_multiplier</name>
            <value>1.2</value>
         </property>
         <property>
            <name>netapp_snapmirror_quiesce_timeout</name>
            <value>3600</value>
         </property>
         <property>
            <name>netapp_transport_type</name>
            <value>http</value>
         </property>
      </driver_options>
   </storage>
   <host>
      <name>host_mixed_1</name>
   </host>
</storage_domain

NetApp credentials :
Management: https://10.46.2.1/sysmgr/SysMgr.html
user: qeadmin
password: Qum10net
Comment 2 Avihai 2019-03-18 11:00:59 UTC 
Created attachment 1545188 [details]
NetApp free space print screen
Comment 3 Benny Zlotnik 2019-03-18 11:48:21 UTC 
I don't know how the storage backend works, 
if you look at the cinderlib logs (possible since 4.3.2), you will see:

2019-03-18 13:45:47,829 - cinder.volume.drivers.netapp.dataontap.block_base - ERROR - Exception creating LUN volume-448a3ce6-c339-462d-a5d5-96857e53e064 in pool test1.
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/netapp/dataontap/block_base.py", line 243, in create_volume
    qos_policy_group_name)
  File "/usr/lib/python2.7/site-packages/cinder/utils.py", line 849, in trace_method_logging_wrapper
    return f(*args, **kwargs)
  File "/usr/lib/python2.7/site-packages/cinder/utils.py", line 849, in trace_method_logging_wrapper
    return f(*args, **kwargs)
  File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/netapp/dataontap/block_cmode.py", line 172, in _create_lun
    volume_name, lun_name, size, metadata, qos_policy_group_name)
  File "/usr/lib/python2.7/site-packages/cinder/utils.py", line 849, in trace_method_logging_wrapper
    return f(*args, **kwargs)
  File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/netapp/dataontap/client/client_base.py", line 112, in create_lun
    'ex': ex})
  File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
    self.force_reraise()
  File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
    six.reraise(self.type_, self.value, self.tb)
  File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/netapp/dataontap/client/client_base.py", line 105, in create_lun
    self.connection.invoke_successfully(lun_create, True)
  File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/netapp/dataontap/client/api.py", line 227, in invoke_successfully
    raise NaApiError(code, msg)
NaApiError: NetApp API failed. Reason - 28:No space left on device
Comment 4 Avihai 2019-03-18 12:44:43 UTC 
(In reply to Benny Zlotnik from comment #3)
> I don't know how the storage backend works, 
> if you look at the cinderlib logs (possible since 4.3.2), you will see:
> 
> 2019-03-18 13:45:47,829 - cinder.volume.drivers.netapp.dataontap.block_base
> - ERROR - Exception creating LUN volume-448a3ce6-c339-462d-a5d5-96857e53e064
> in pool test1.
> Traceback (most recent call last):
>   File
> "/usr/lib/python2.7/site-packages/cinder/volume/drivers/netapp/dataontap/
> block_base.py", line 243, in create_volume
>     qos_policy_group_name)
>   File "/usr/lib/python2.7/site-packages/cinder/utils.py", line 849, in
> trace_method_logging_wrapper
>     return f(*args, **kwargs)
>   File "/usr/lib/python2.7/site-packages/cinder/utils.py", line 849, in
> trace_method_logging_wrapper
>     return f(*args, **kwargs)
>   File
> "/usr/lib/python2.7/site-packages/cinder/volume/drivers/netapp/dataontap/
> block_cmode.py", line 172, in _create_lun
>     volume_name, lun_name, size, metadata, qos_policy_group_name)
>   File "/usr/lib/python2.7/site-packages/cinder/utils.py", line 849, in
> trace_method_logging_wrapper
>     return f(*args, **kwargs)
>   File
> "/usr/lib/python2.7/site-packages/cinder/volume/drivers/netapp/dataontap/
> client/client_base.py", line 112, in create_lun
>     'ex': ex})
>   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220,
> in __exit__
>     self.force_reraise()
>   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196,
> in force_reraise
>     six.reraise(self.type_, self.value, self.tb)
>   File
> "/usr/lib/python2.7/site-packages/cinder/volume/drivers/netapp/dataontap/
> client/client_base.py", line 105, in create_lun
>     self.connection.invoke_successfully(lun_create, True)
>   File
> "/usr/lib/python2.7/site-packages/cinder/volume/drivers/netapp/dataontap/
> client/api.py", line 227, in invoke_successfully
>     raise NaApiError(code, msg)
> NaApiError: NetApp API failed. Reason - 28:No space left on device

As we saw the NetApp storage have a lot of space and creating a volume/LUN manually with 1G/10G size works without issues.
Maybe this is a cinderLib request or NetApp bug?
Comment 5 Benny Zlotnik 2019-03-18 14:41:11 UTC 
As discussed on IRC, since `netapp_pool_name_search_pattern` was not set, which probably caused it to use the test1 pool which has only 900MB~
Using something like:
         <property>
         	<name>netapp_pool_name_search_pattern</name>
         	<value>vol_ge_4</value>
         </property>
in the driver options should resolve the issue