Bug 1256484

Summary: cinder.volume.drivers.vmware.api fails due to session authentication errors
Product: Red Hat OpenStack Reporter: Jaison Raju <jraju>
Component: openstack-cinderAssignee: Eric Harney <eharney>
Status: CLOSED WONTFIX QA Contact: nlevinki <nlevinki>
Severity: high Docs Contact:
Priority: high    
Version: 6.0 (Juno)CC: eharney, jraju, mburns, morazi, rhos-maint, scohen, sgordon, sgotliv, sknauss, tjones, yeylon
Target Milestone: ---Keywords: Unconfirmed
Target Release: 6.0 (Juno)   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2015-12-15 13:13:25 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
cinder info none

Description Jaison Raju 2015-08-24 17:31:42 UTC
Created attachment 1066567 [details]
cinder info

Description of problem:
creating a cinder volume via public API fails due to session authentication issues.

Version-Release number of selected component (if applicable):


How reproducible:
Always on customer end

Steps to Reproduce:
1.
2.
3.

Actual results:
Cinder volume creation fails .

Expected results:
Cinder volume is created

Additional info:
2015-08-18 12:33:22.103 132476 DEBUG cinder.volume.drivers.vmware.api [-] Checking if the current session: 52bbb51f-982d-2144-5cc5-7433d6e37302 is active. _is_current_session_active /usr/lib/python2.7/site-packa
ges/cinder/volume/drivers/vmware/api.py:262
2015-08-18 12:33:22.107 132476 DEBUG cinder.volume.drivers.vmware.api [-] Checking if the current session: 52bbb51f-982d-2144-5cc5-7433d6e37302 is active. _is_current_session_active /usr/lib/python2.7/site-packa
ges/cinder/volume/drivers/vmware/api.py:262
2015-08-18 12:33:22.120 132476 ERROR suds.client [-] <?xml version="1.0" encoding="UTF-8"?>
<SOAP-ENV:Envelope xmlns:ns0="urn:vim25" xmlns:ns1="http://schemas.xmlsoap.org/soap/envelope/" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/">
   <ns1:Body>
      <ns0:SessionIsActive>
         <ns0:_this type="SessionManager">SessionManager</ns0:_this>
         <ns0:sessionID>52bbb51f-982d-2144-5cc5-7433d6e37302</ns0:sessionID>
         <ns0:userName>MUNICHRE\ser-enterprisemrcpvc</ns0:userName>
      </ns0:SessionIsActive>
   </ns1:Body>
</SOAP-ENV:Envelope>
2015-08-18 12:33:22.121 132476 WARNING cinder.volume.drivers.vmware.api [-] Error occurred while checking whether the current session: 52bbb51f-982d-2144-5cc5-7433d6e37302 is active.
2015-08-18 12:33:22.121 132476 TRACE cinder.volume.drivers.vmware.api Traceback (most recent call last):
2015-08-18 12:33:22.121 132476 TRACE cinder.volume.drivers.vmware.api   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/api.py", line 269, in _is_current_session_active
2015-08-18 12:33:22.121 132476 TRACE cinder.volume.drivers.vmware.api     userName=self._session_username)
2015-08-18 12:33:22.121 132476 TRACE cinder.volume.drivers.vmware.api   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/vim.py", line 182, in vim_request_handler
2015-08-18 12:33:22.121 132476 TRACE cinder.volume.drivers.vmware.api     raise error_util.VimFaultException(fault_list, excep)
2015-08-18 12:33:22.121 132476 TRACE cinder.volume.drivers.vmware.api VimFaultException: Server raised fault: 'The session is not authenticated.'
2015-08-18 12:33:22.121 132476 TRACE cinder.volume.drivers.vmware.api 
2015-08-18 12:33:22.122 132476 WARNING cinder.volume.drivers.vmware.api [-] Current session: 52bbb51f-982d-2144-5cc5-7433d6e37302 is inactive; re-creating the session while invoking method <module 'cinder.volume
.drivers.vmware.vim_util' from '/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/vim_util.pyc'>.get_objects.
2015-08-18 12:33:22.122 132476 TRACE cinder.volume.drivers.vmware.api Traceback (most recent call last):
2015-08-18 12:33:22.122 132476 TRACE cinder.volume.drivers.vmware.api   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/api.py", line 223, in _invoke_api
2015-08-18 12:33:22.122 132476 TRACE cinder.volume.drivers.vmware.api     return api_method(*args, **kwargs)
2015-08-18 12:33:22.122 132476 TRACE cinder.volume.drivers.vmware.api   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/vim_util.py", line 227, in get_objects
2015-08-18 12:33:22.122 132476 TRACE cinder.volume.drivers.vmware.api     options=options)
2015-08-18 12:33:22.122 132476 TRACE cinder.volume.drivers.vmware.api   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/vim.py", line 169, in vim_request_handler
2015-08-18 12:33:22.122 132476 TRACE cinder.volume.drivers.vmware.api     retrieve_properties_ex_fault_checker(response)
2015-08-18 12:33:22.122 132476 TRACE cinder.volume.drivers.vmware.api   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/vim.py", line 148, in retrieve_properties_ex_fault_checker
2015-08-18 12:33:22.122 132476 TRACE cinder.volume.drivers.vmware.api     exc_msg_list)
2015-08-18 12:33:22.122 132476 TRACE cinder.volume.drivers.vmware.api VimFaultException: Error(s): NotAuthenticated occurred in the call to RetrievePropertiesEx.
2015-08-18 12:33:22.122 132476 TRACE cinder.volume.drivers.vmware.api 
2015-08-18 12:33:22.129 132476 ERROR suds.client [-] <?xml version="1.0" encoding="UTF-8"?>
<SOAP-ENV:Envelope xmlns:ns0="urn:vim25" xmlns:ns1="http://schemas.xmlsoap.org/soap/envelope/" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/">
   <ns1:Body>
      <ns0:Login>
         <ns0:_this type="SessionManager">SessionManager</ns0:_this>
         <ns0:userName>munichre\ser-enterprisemrcpvc</ns0:userName>
         <ns0:userName>munichre\ser-enterprisemrcpvc</ns0:userName>
         <ns0:password>Utg0we39I8cr!</ns0:password>
      </ns0:Login>
   </ns1:Body>
</SOAP-ENV:Envelope>
2015-08-18 12:33:22.130 132476 WARNING cinder.volume.drivers.vmware.api [-] Error occurred while checking whether the current session: 52bbb51f-982d-2144-5cc5-7433d6e37302 is active.
2015-08-18 12:33:22.130 132476 TRACE cinder.volume.drivers.vmware.api Traceback (most recent call last):
2015-08-18 12:33:22.130 132476 TRACE cinder.volume.drivers.vmware.api   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/api.py", line 269, in _is_current_session_active
2015-08-18 12:33:22.130 132476 TRACE cinder.volume.drivers.vmware.api     userName=self._session_username)
2015-08-18 12:33:22.130 132476 TRACE cinder.volume.drivers.vmware.api   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/vim.py", line 182, in vim_request_handler
2015-08-18 12:33:22.130 132476 TRACE cinder.volume.drivers.vmware.api     raise error_util.VimFaultException(fault_list, excep)
2015-08-18 12:33:22.130 132476 TRACE cinder.volume.drivers.vmware.api VimFaultException: Server raised fault: 'The session is not authenticated.'
2015-08-18 12:33:22.130 132476 TRACE cinder.volume.drivers.vmware.api 
2015-08-18 12:33:22.130 132476 WARNING cinder.volume.drivers.vmware.api [-] Current session: 52bbb51f-982d-2144-5cc5-7433d6e37302 is inactive; re-creating the session while invoking method <module 'cinder.volume.drivers.vmware.vim_util' from '/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/vim_util.pyc'>.get_objects.
2015-08-18 12:33:22.130 132476 TRACE cinder.volume.drivers.vmware.api Traceback (most recent call last):
2015-08-18 12:33:22.130 132476 TRACE cinder.volume.drivers.vmware.api   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/api.py", line 223, in _invoke_api
2015-08-18 12:33:22.130 132476 TRACE cinder.volume.drivers.vmware.api     return api_method(*args, **kwargs)
2015-08-18 12:33:22.130 132476 TRACE cinder.volume.drivers.vmware.api   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/vim_util.py", line 227, in get_objects
2015-08-18 12:33:22.130 132476 TRACE cinder.volume.drivers.vmware.api     options=options)
2015-08-18 12:33:22.130 132476 TRACE cinder.volume.drivers.vmware.api   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/vim.py", line 169, in vim_request_handler
2015-08-18 12:33:22.130 132476 TRACE cinder.volume.drivers.vmware.api     retrieve_properties_ex_fault_checker(response)
2015-08-18 12:33:22.130 132476 TRACE cinder.volume.drivers.vmware.api   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/vim.py", line 148, in retrieve_properties_ex_fault_checker
2015-08-18 12:33:22.130 132476 TRACE cinder.volume.drivers.vmware.api     exc_msg_list)
2015-08-18 12:33:22.130 132476 TRACE cinder.volume.drivers.vmware.api VimFaultException: Error(s): NotAuthenticated occurred in the call to RetrievePropertiesEx.
2015-08-18 12:33:22.130 132476 TRACE cinder.volume.drivers.vmware.api 
2015-08-18 12:33:22.329 132476 ERROR suds.client [-] <?xml version="1.0" encoding="UTF-8"?>
<SOAP-ENV:Envelope xmlns:ns0="urn:vim25" xmlns:ns1="http://schemas.xmlsoap.org/soap/envelope/" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/">
   <ns1:Body>
      <ns0:TerminateSession>
         <ns0:_this type="SessionManager">SessionManager</ns0:_this>
         <ns0:sessionId>52bbb51f-982d-2144-5cc5-7433d6e37302</ns0:sessionId>
      </ns0:TerminateSession>
   </ns1:Body>
</SOAP-ENV:Envelope>
2015-08-18 12:33:22.330 132476 ERROR cinder.openstack.common.loopingcall [-] in dynamic looping call
2015-08-18 12:33:22.330 132476 TRACE cinder.openstack.common.loopingcall Traceback (most recent call last):
2015-08-18 12:33:22.330 132476 TRACE cinder.openstack.common.loopingcall   File "/usr/lib/python2.7/site-packages/cinder/openstack/common/loopingcall.py", line 124, in _inner
2015-08-18 12:33:22.330 132476 TRACE cinder.openstack.common.loopingcall     idle = self.f(*self.args, **self.kw)
2015-08-18 12:33:22.330 132476 TRACE cinder.openstack.common.loopingcall   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/api.py", line 83, in _func
2015-08-18 12:33:22.330 132476 TRACE cinder.openstack.common.loopingcall     raise excep
2015-08-18 12:33:22.330 132476 TRACE cinder.openstack.common.loopingcall VimFaultException: Server raised fault: 'Cannot complete login due to an incorrect user name or password.'
2015-08-18 12:33:22.330 132476 TRACE cinder.openstack.common.loopingcall 
2015-08-18 12:33:22.331 132476 ERROR cinder.openstack.common.loopingcall [-] in dynamic looping call
2015-08-18 12:33:22.331 132476 TRACE cinder.openstack.common.loopingcall Traceback (most recent call last):
2015-08-18 12:33:22.331 132476 TRACE cinder.openstack.common.loopingcall   File "/usr/lib/python2.7/site-packages/cinder/openstack/common/loopingcall.py", line 124, in _inner
2015-08-18 12:33:22.331 132476 TRACE cinder.openstack.common.loopingcall     idle = self.f(*self.args, **self.kw)
2015-08-18 12:33:22.331 132476 TRACE cinder.openstack.common.loopingcall   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/api.py", line 83, in _func
2015-08-18 12:33:22.331 132476 TRACE cinder.openstack.common.loopingcall     raise excep
2015-08-18 12:33:22.331 132476 TRACE cinder.openstack.common.loopingcall VimFaultException: Server raised fault: 'Cannot complete login due to an incorrect user name or password.'
2015-08-18 12:33:22.331 132476 TRACE cinder.openstack.common.loopingcall 
2015-08-18 12:33:22.332 132476 ERROR cinder.volume.drivers.vmware.vmdk [req-da815db3-8512-4b8d-957a-946b52108463 c7cd77f29af74649aebab0e77a21b5e2 5c038ea3bb604ab4be7ee97dc4762f77 - - -] Not able to find a suitable datastore for the volume: volume-935633f3-8445-44b1-a3a8-43bb524f23b8.
2015-08-18 12:33:22.332 132476 TRACE cinder.volume.drivers.vmware.vmdk Traceback (most recent call last):
2015-08-18 12:33:22.332 132476 TRACE cinder.volume.drivers.vmware.vmdk   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/vmdk.py", line 304, in _verify_volume_creation
2015-08-18 12:33:22.332 132476 TRACE cinder.volume.drivers.vmware.vmdk     self._select_ds_for_volume(volume)
2015-08-18 12:33:22.332 132476 TRACE cinder.volume.drivers.vmware.vmdk   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/vmdk.py", line 570, in _select_ds_for_volume
2015-08-18 12:33:22.332 132476 TRACE cinder.volume.drivers.vmware.vmdk     retrv_result = self.volumeops.get_hosts()
2015-08-18 12:33:22.332 132476 TRACE cinder.volume.drivers.vmware.vmdk   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/volumeops.py", line 327, in get_hosts
2015-08-18 12:33:22.332 132476 TRACE cinder.volume.drivers.vmware.vmdk     'HostSystem', self._max_objects)
2015-08-18 12:33:22.332 132476 TRACE cinder.volume.drivers.vmware.vmdk   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/api.py", line 254, in invoke_api
2015-08-18 12:33:22.332 132476 TRACE cinder.volume.drivers.vmware.vmdk     return _invoke_api(module, method, *args, **kwargs)
2015-08-18 12:33:22.332 132476 TRACE cinder.volume.drivers.vmware.vmdk   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/api.py", line 90, in func
2015-08-18 12:33:22.332 132476 TRACE cinder.volume.drivers.vmware.vmdk     return timer.wait()
2015-08-18 12:33:22.332 132476 TRACE cinder.volume.drivers.vmware.vmdk   File "/usr/lib/python2.7/site-packages/eventlet/event.py", line 121, in wait
2015-08-18 12:33:22.332 132476 TRACE cinder.volume.drivers.vmware.vmdk     return hubs.get_hub().switch()
2015-08-18 12:33:22.332 132476 TRACE cinder.volume.drivers.vmware.vmdk   File "/usr/lib/python2.7/site-packages/eventlet/hubs/hub.py", line 293, in switch
2015-08-18 12:33:22.332 132476 TRACE cinder.volume.drivers.vmware.vmdk     return self.greenlet.switch()
2015-08-18 12:33:22.332 132476 TRACE cinder.volume.drivers.vmware.vmdk   File "/usr/lib/python2.7/site-packages/cinder/openstack/common/loopingcall.py", line 124, in _inner
2015-08-18 12:33:22.332 132476 TRACE cinder.volume.drivers.vmware.vmdk     idle = self.f(*self.args, **self.kw)
2015-08-18 12:33:22.332 132476 TRACE cinder.volume.drivers.vmware.vmdk   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/api.py", line 83, in _func
2015-08-18 12:33:22.332 132476 TRACE cinder.volume.drivers.vmware.vmdk     raise excep
2015-08-18 12:33:22.332 132476 TRACE cinder.volume.drivers.vmware.vmdk VimFaultException: Server raised fault: 'Cannot complete login due to an incorrect user name or password.'
2015-08-18 12:33:22.332 132476 TRACE cinder.volume.drivers.vmware.vmdk 
2015-08-18 12:33:22.334 132476 WARNING cinder.volume.manager [req-da815db3-8512-4b8d-957a-946b52108463 c7cd77f29af74649aebab0e77a21b5e2 5c038ea3bb604ab4be7ee97dc4762f77 - - -] Task 'cinder.volume.flows.manager.create_volume.CreateVolumeFromSpecTask;volume:create' (621b8325-2657-48c1-b939-733cbfb08db9) transitioned into state 'FAILURE'
2015-08-18 12:33:22.334 132476 TRACE cinder.volume.manager Traceback (most recent call last):
2015-08-18 12:33:22.334 132476 TRACE cinder.volume.manager   File "/usr/lib/python2.7/site-packages/taskflow/engines/action_engine/executor.py", line 34, in _execute_task
2015-08-18 12:33:22.334 132476 TRACE cinder.volume.manager     result = task.execute(**arguments)
2015-08-18 12:33:22.334 132476 TRACE cinder.volume.manager   File "/usr/lib/python2.7/site-packages/cinder/volume/flows/manager/create_volume.py", line 624, in execute
2015-08-18 12:33:22.334 132476 TRACE cinder.volume.manager     **volume_spec)
2015-08-18 12:33:22.334 132476 TRACE cinder.volume.manager   File "/usr/lib/python2.7/site-packages/cinder/volume/flows/manager/create_volume.py", line 598, in _create_raw_volume
2015-08-18 12:33:22.334 132476 TRACE cinder.volume.manager     return self.driver.create_volume(volume_ref)
2015-08-18 12:33:22.334 132476 TRACE cinder.volume.manager   File "/usr/lib/python2.7/site-packages/osprofiler/profiler.py", line 105, in wrapper
2015-08-18 12:33:22.334 132476 TRACE cinder.volume.manager     return f(*args, **kwargs)
2015-08-18 12:33:22.334 132476 TRACE cinder.volume.manager   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/vmdk.py", line 320, in create_volume
2015-08-18 12:33:22.334 132476 TRACE cinder.volume.manager     self._verify_volume_creation(volume)
2015-08-18 12:33:22.334 132476 TRACE cinder.volume.manager   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/vmdk.py", line 309, in _verify_volume_creation
2015-08-18 12:33:22.334 132476 TRACE cinder.volume.manager     raise error_util.VimFaultException([excep], msg)
2015-08-18 12:33:22.334 132476 TRACE cinder.volume.manager VimFaultException: Not able to find a suitable datastore for the volume: volume-935633f3-8445-44b1-a3a8-43bb524f23b8.
2015-08-18 12:33:22.334 132476 TRACE cinder.volume.manager 
2015-08-18 12:33:22.335 132476 WARNING cinder.volume.manager [req-da815db3-8512-4b8d-957a-946b52108463 c7cd77f29af74649aebab0e77a21b5e2 5c038ea3bb604ab4be7ee97dc4762f77 - - -] Task 'cinder.volume.flows.manager.create_volume.CreateVolumeFromSpecTask;volume:create' (621b8325-2657-48c1-b939-733cbfb08db9) transitioned into state 'REVERTING'

Comment 4 Jaison Raju 2015-08-25 13:15:48 UTC
I missed out another important information :
Customer's external tool gets first the error state and stops, but the volume is available at the storage end .

Comment 12 Stephen Gordon 2015-09-14 13:31:50 UTC
Looking at the included cinder.conf:

# IP address for connecting to VMware ESX/VC server. (string
# value)
#vmware_host_ip=<None>

# Username for authenticating with VMware ESX/VC server.
# (string value)
#vmware_host_username=<None>

# Password for authenticating with VMware ESX/VC server.
# (string value)
#vmware_host_password=<None>

???

Comment 13 Stephen Gordon 2015-09-14 13:33:55 UTC
(In reply to Stephen Gordon from comment #12)
> Looking at the included cinder.conf:
> 
> # IP address for connecting to VMware ESX/VC server. (string
> # value)
> #vmware_host_ip=<None>
> 
> # Username for authenticating with VMware ESX/VC server.
> # (string value)
> #vmware_host_username=<None>
> 
> # Password for authenticating with VMware ESX/VC server.
> # (string value)
> #vmware_host_password=<None>
> 
> ???

Nevermind found the set values at the bottom, are we 100% sure they are correct. Read: can they be used to connect to the system externally to OpenStack?

Comment 14 Stephen Gordon 2015-09-14 13:38:47 UTC
One other thing to check is the setup of the VMware service account being used, does it have the permissions denoted under "VMware vCenter service account" over the datacenter object(s)?:

http://docs.openstack.org/kilo/config-reference/content/vmware.html

Comment 15 Jaison Raju 2015-09-29 06:32:24 UTC
(In reply to Stephen Gordon from comment #14)
> One other thing to check is the setup of the VMware service account being
> used, does it have the permissions denoted under "VMware vCenter service
> account" over the datacenter object(s)?:
> 
> http://docs.openstack.org/kilo/config-reference/content/vmware.html

The login data is working as the cinder volume could not be successfully created.
Customer has configured this as per the upstream doc :
http://docs.openstack.org/kilo/config-reference/content/vmware.html

Not sure how to proceed further .

Regards,
Jaison R

Comment 16 Jaison Raju 2015-09-29 12:40:27 UTC
Opps ..
What i meant was :
The login data is working as the cinder volume could be successfully created.
:)

Comment 21 Stephen Gordon 2015-10-19 18:23:23 UTC
Can we get Keystone logs attached to the bug as well please (ideally a full sosreport)?

Comment 22 Tracy Jones 2015-10-20 00:43:00 UTC
Never mind - our cinder lead said this about the bug

As per the log this is due to:
https://bugs.launchpad.net/oslo.vmware/+bug/1409014

It is fixed only in oslo.vmware. So the older versions of driver which do not use oslo.vmware (Icehouse, Juno) will have this bug. Also from the logs it is clear that they are using Juno.
But the fix is easy to apply manually using the oslo.vmware fix (https://review.openstack.org/#/c/146090/).

Comment 24 Sergey Gotliv 2015-10-20 11:01:58 UTC
Tracy,

Thanks for the prompt response.

Jaison,

I had to adjust this patch https://review.openstack.org/#/c/146090/ to the Juno code base. We still have to review this internally. Would your customer ready to test it on his environment?

Comment 25 Jaison Raju 2015-10-21 13:04:47 UTC
(In reply to Sergey Gotliv from comment #24)
> Tracy,
> 
> Thanks for the prompt response.
> 
> Jaison,
> 
> I had to adjust this patch https://review.openstack.org/#/c/146090/ to the
> Juno code base. We still have to review this internally. Would your customer
> ready to test it on his environment?

Yes .