Attachment 919121 Details for Bug 1121191 – log

log

file_1121191.txt (text/plain), 65.67 KB, created by Jaroslav Henner on 2014-07-18 15:25:16 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Jaroslav Henner

Created: 2014-07-18 15:25:16 UTC

Size: 65.67 KB

patch

obsolete

>[root@jhenner-node-7v0 ~(keystone_admin)]# vim /etc/cinder/cinder.conf 
>[root@jhenner-node-7v0 ~(keystone_admin)]# ^C
>[root@jhenner-node-7v0 ~(keystone_admin)]# cinder delete a0bbca53-49f5-4bc8-b90c-74e422cffc1c^C
>[root@jhenner-node-7v0 ~(keystone_admin)]# . keystonerc_admin 
>[root@jhenner-node-7v0 ~(keystone_admin)]# cinder create --display-name vol1 1
>+---------------------+--------------------------------------+
>|       Property      |                Value                 |
>+---------------------+--------------------------------------+
>|     attachments     |                  []                  |
>|  availability_zone  |                 nova                 |
>|       bootable      |                false                 |
>|      created_at     |      2014-07-18T15:11:52.299204      |
>| display_description |                 None                 |
>|     display_name    |                 vol1                 |
>|      encrypted      |                False                 |
>|          id         | 545f8321-4be0-4f3b-a502-bd2811947b07 |
>|       metadata      |                  {}                  |
>|         size        |                  1                   |
>|     snapshot_id     |                 None                 |
>|     source_volid    |                 None                 |
>|        status       |               creating               |
>|     volume_type     |                 None                 |
>+---------------------+--------------------------------------+
>[root@jhenner-node-7v0 ~(keystone_admin)]# tail -f /var/log/cinder/volume.log 
> will remain and continue to be supported.
>2014-07-18 08:57:05.229 22647 INFO cinder.openstack.common.service [-] Starting 1 workers
>2014-07-18 08:57:05.231 22647 INFO cinder.openstack.common.service [-] Started child 22666
>2014-07-18 08:57:05.242 22647 DEBUG cinder.openstack.common.service [-] Full set of CONF: wait /usr/lib/python2.7/site-packages/cinder/openstack/common/service.py:387
>
>...
>
>2014-07-18 11:11:54.139 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Edges: 5 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:54.140 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]    cinder.volume.flows.manager.create_volume.ExtractVolumeRefTask;volume:create==1.0 -> cinder.volume.flows.manager.create_volume.OnFailureRescheduleTask;volume:create==1.0 ({'flatten': True}) wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:54.141 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]    cinder.volume.flows.manager.create_volume.CreateVolumeFromSpecTask;volume:create==1.0 -> cinder.volume.flows.manager.create_volume.CreateVolumeOnFinishTask;volume:create, create.end==1.0 ({'flatten': True}) wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:54.141 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]    cinder.volume.flows.manager.create_volume.NotifyVolumeActionTask;volume:create, create.start==1.0 -> cinder.volume.flows.manager.create_volume.CreateVolumeFromSpecTask;volume:create==1.0 ({'flatten': True}) wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:54.143 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]    cinder.volume.flows.manager.create_volume.ExtractVolumeSpecTask;volume:create==1.0 -> cinder.volume.flows.manager.create_volume.NotifyVolumeActionTask;volume:create, create.start==1.0 ({'flatten': True}) wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:54.144 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]    cinder.volume.flows.manager.create_volume.OnFailureRescheduleTask;volume:create==1.0 -> cinder.volume.flows.manager.create_volume.ExtractVolumeSpecTask;volume:create==1.0 ({'flatten': True}) wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:54.144 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Density: 0.167 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:54.145 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Cycles: 0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:54.201 22666 DEBUG oslo.messaging._drivers.amqp [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] UNIQUE_ID is a4694644daa34b2b8c543d3ccc42f241. _add_unique_id /usr/lib/python2.7/site-packages/oslo/messaging/_drivers/amqp.py:338
>2014-07-18 11:11:54.215 22666 INFO cinder.volume.flows.manager.create_volume [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] Volume 545f8321-4be0-4f3b-a502-bd2811947b07: being created using CreateVolumeFromSpecTask._create_raw_volume with specification: {'status': u'error', 'volume_size': 1, 'volume_name': u'volume-545f8321-4be0-4f3b-a502-bd2811947b07'}
>2014-07-18 11:11:54.928 22666 DEBUG cinder.volume.drivers.vmware.api [-] Checking if the current session: 521110c6-5abc-2e80-b38b-11c9723f809b is active. _is_current_session_active /usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/api.py:260
>2014-07-18 11:11:55.510 22666 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>521110c6-5abc-2e80-b38b-11c9723f809b</ns0:sessionID>
>         <ns0:userName>root</ns0:userName>
>      </ns0:SessionIsActive>
>   </ns1:Body>
></SOAP-ENV:Envelope>
>2014-07-18 11:11:55.516 22666 ERROR cinder.openstack.common.loopingcall [-] in dynamic looping call
>2014-07-18 11:11:55.516 22666 TRACE cinder.openstack.common.loopingcall Traceback (most recent call last):
>2014-07-18 11:11:55.516 22666 TRACE cinder.openstack.common.loopingcall   File "/usr/lib/python2.7/site-packages/cinder/openstack/common/loopingcall.py", line 123, in _inner
>2014-07-18 11:11:55.516 22666 TRACE cinder.openstack.common.loopingcall     idle = self.f(*self.args, **self.kw)
>2014-07-18 11:11:55.516 22666 TRACE cinder.openstack.common.loopingcall   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/api.py", line 82, in _func
>2014-07-18 11:11:55.516 22666 TRACE cinder.openstack.common.loopingcall     raise excep
>2014-07-18 11:11:55.516 22666 TRACE cinder.openstack.common.loopingcall VimFaultException: Server raised fault: 'The session is not authenticated.'
>2014-07-18 11:11:55.516 22666 TRACE cinder.openstack.common.loopingcall 
>2014-07-18 11:11:55.522 22666 DEBUG cinder.volume.flows.manager.create_volume [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] Updating volume 545f8321-4be0-4f3b-a502-bd2811947b07 with {'status': 'creating', 'scheduled_at': datetime.datetime(2014, 7, 18, 15, 11, 55, 521839)}. _pre_reschedule /usr/lib/python2.7/site-packages/cinder/volume/flows/manager/create_volume.py:138
>2014-07-18 11:11:55.584 22666 DEBUG cinder.volume.flows.manager.create_volume [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] Volume 545f8321-4be0-4f3b-a502-bd2811947b07: re-scheduling SchedulerAPI.create_volume attempt 2 due to Server raised fault: 'The session is not authenticated.' _reschedule /usr/lib/python2.7/site-packages/cinder/volume/flows/manager/create_volume.py:106
>2014-07-18 11:11:55.587 22666 DEBUG oslo.messaging._drivers.amqp [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] UNIQUE_ID is 75f0c95fcd2b49f1a47370cfac098045. _add_unique_id /usr/lib/python2.7/site-packages/oslo/messaging/_drivers/amqp.py:338
>2014-07-18 11:11:55.611 22666 DEBUG cinder.volume.flows.manager.create_volume [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] Volume 545f8321-4be0-4f3b-a502-bd2811947b07: re-scheduled _post_reschedule /usr/lib/python2.7/site-packages/cinder/volume/flows/manager/create_volume.py:120
>2014-07-18 11:11:55.613 22666 DEBUG cinder.volume.flows.common [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] Updating volume: 545f8321-4be0-4f3b-a502-bd2811947b07 with {'status': 'error'} due to: ??? error_out_volume /usr/lib/python2.7/site-packages/cinder/volume/flows/common.py:87
>2014-07-18 11:11:55.722 22666 ERROR cinder.volume.flows.manager.create_volume [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] Volume 545f8321-4be0-4f3b-a502-bd2811947b07: create failed
>2014-07-18 11:11:55.723 22666 ERROR oslo.messaging.rpc.dispatcher [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] Exception during message handling: Server raised fault: 'The session is not authenticated.'
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher Traceback (most recent call last):
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 133, in _dispatch_and_reply
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher     incoming.message))
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 176, in _dispatch
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher     return self._do_dispatch(endpoint, method, ctxt, args)
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 122, in _do_dispatch
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher     result = getattr(endpoint, method)(ctxt, **new_args)
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/volume/manager.py", line 363, in create_volume
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher     _run_flow()
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/volume/manager.py", line 356, in _run_flow
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher     flow_engine.run()
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/taskflow/utils/lock_utils.py", line 51, in wrapper
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher     return f(*args, **kwargs)
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/taskflow/engines/action_engine/engine.py", line 118, in run
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher     self._run()
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/taskflow/engines/action_engine/engine.py", line 128, in _run
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher     self._revert(misc.Failure())
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/taskflow/engines/action_engine/engine.py", line 81, in _revert
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher     misc.Failure.reraise_if_any(failures.values())
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/taskflow/utils/misc.py", line 487, in reraise_if_any
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher     failures[0].reraise()
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/taskflow/utils/misc.py", line 494, in reraise
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher     six.reraise(*self._exc_info)
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/taskflow/engines/action_engine/executor.py", line 36, in _execute_task
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher     result = task.execute(**arguments)
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/volume/flows/manager/create_volume.py", line 594, in execute
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher     **volume_spec)
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/volume/flows/manager/create_volume.py", line 564, in _create_raw_volume
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher     return self.driver.create_volume(volume_ref)
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/vmdk.py", line 262, in create_volume
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher     self._verify_volume_creation(volume)
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/vmdk.py", line 246, in _verify_volume_creation
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher     self._select_ds_for_volume(volume)
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/vmdk.py", line 468, in _select_ds_for_volume
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher     retrv_result = self.volumeops.get_hosts()
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/volumeops.py", line 121, in get_hosts
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher     'HostSystem', self._max_objects)
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/api.py", line 252, in invoke_api
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher     return _invoke_api(module, method, *args, **kwargs)
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/api.py", line 89, in func
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher     return timer.wait()
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/eventlet/event.py", line 116, in wait
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher     return hubs.get_hub().switch()
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/eventlet/hubs/hub.py", line 187, in switch
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher     return self.greenlet.switch()
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/openstack/common/loopingcall.py", line 123, in _inner
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher     idle = self.f(*self.args, **self.kw)
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/api.py", line 82, in _func
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher     raise excep
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher VimFaultException: Server raised fault: 'The session is not authenticated.'
>2014-07-18 11:11:55.723 22666 TRACE oslo.messaging.rpc.dispatcher 
>2014-07-18 11:11:55.728 22666 ERROR oslo.messaging._drivers.common [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] Returning exception Server raised fault: 'The session is not authenticated.' to caller
>2014-07-18 11:11:55.729 22666 ERROR oslo.messaging._drivers.common [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] ['Traceback (most recent call last):\n', '  File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 133, in _dispatch_and_reply\n    incoming.message))\n', '  File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 176, in _dispatch\n    return self._do_dispatch(endpoint, method, ctxt, args)\n', '  File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 122, in _do_dispatch\n    result = getattr(endpoint, method)(ctxt, **new_args)\n', '  File "/usr/lib/python2.7/site-packages/cinder/volume/manager.py", line 363, in create_volume\n    _run_flow()\n', '  File "/usr/lib/python2.7/site-packages/cinder/volume/manager.py", line 356, in _run_flow\n    flow_engine.run()\n', '  File "/usr/lib/python2.7/site-packages/taskflow/utils/lock_utils.py", line 51, in wrapper\n    return f(*args, **kwargs)\n', '  File "/usr/lib/python2.7/site-packages/taskflow/engines/action_engine/engine.py", line 118, in run\n    self._run()\n', '  File "/usr/lib/python2.7/site-packages/taskflow/engines/action_engine/engine.py", line 128, in _run\n    self._revert(misc.Failure())\n', '  File "/usr/lib/python2.7/site-packages/taskflow/engines/action_engine/engine.py", line 81, in _revert\n    misc.Failure.reraise_if_any(failures.values())\n', '  File "/usr/lib/python2.7/site-packages/taskflow/utils/misc.py", line 487, in reraise_if_any\n    failures[0].reraise()\n', '  File "/usr/lib/python2.7/site-packages/taskflow/utils/misc.py", line 494, in reraise\n    six.reraise(*self._exc_info)\n', '  File "/usr/lib/python2.7/site-packages/taskflow/engines/action_engine/executor.py", line 36, in _execute_task\n    result = task.execute(**arguments)\n', '  File "/usr/lib/python2.7/site-packages/cinder/volume/flows/manager/create_volume.py", line 594, in execute\n    **volume_spec)\n', '  File "/usr/lib/python2.7/site-packages/cinder/volume/flows/manager/create_volume.py", line 564, in _create_raw_volume\n    return self.driver.create_volume(volume_ref)\n', '  File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/vmdk.py", line 262, in create_volume\n    self._verify_volume_creation(volume)\n', '  File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/vmdk.py", line 246, in _verify_volume_creation\n    self._select_ds_for_volume(volume)\n', '  File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/vmdk.py", line 468, in _select_ds_for_volume\n    retrv_result = self.volumeops.get_hosts()\n', '  File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/volumeops.py", line 121, in get_hosts\n    \'HostSystem\', self._max_objects)\n', '  File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/api.py", line 252, in invoke_api\n    return _invoke_api(module, method, *args, **kwargs)\n', '  File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/api.py", line 89, in func\n    return timer.wait()\n', '  File "/usr/lib/python2.7/site-packages/eventlet/event.py", line 116, in wait\n    return hubs.get_hub().switch()\n', '  File "/usr/lib/python2.7/site-packages/eventlet/hubs/hub.py", line 187, in switch\n    return self.greenlet.switch()\n', '  File "/usr/lib/python2.7/site-packages/cinder/openstack/common/loopingcall.py", line 123, in _inner\n    idle = self.f(*self.args, **self.kw)\n', '  File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/api.py", line 82, in _func\n    raise excep\n', "VimFaultException: Server raised fault: 'The session is not authenticated.'\n"]
>2014-07-18 11:11:55.776 22666 DEBUG oslo.messaging._drivers.amqpdriver [-] received {u'_context_domain': None, u'_context_request_id': u'req-ae13d392-afb7-4096-89d6-cc60e934d4bb', u'_context_quota_class': None, u'_context_service_catalog': [{u'endpoints': [{u'adminURL': u'http://172.16.40.26:8774/v2/2a829d27178843108bc9ca279463634a', u'region': u'RegionOne', u'internalURL': u'http://172.16.40.26:8774/v2/2a829d27178843108bc9ca279463634a', u'id': u'25845b4039334dc68a5ad4893d3ffabe', u'publicURL': u'http://172.16.40.26:8774/v2/2a829d27178843108bc9ca279463634a'}], u'endpoints_links': [], u'type': u'compute', u'name': u'nova'}], u'_context_auth_token': '<SANITIZED>', u'_context_user': u'f3b53899ff5c4233a53c8509ad58bfc1', u'_context_user_id': u'f3b53899ff5c4233a53c8509ad58bfc1', u'_context_is_admin': True, u'version': u'1.4', u'_context_project_domain': None, u'_context_timestamp': u'2014-07-18T15:11:52.202633', u'method': u'create_volume', u'_context_remote_address': u'172.16.40.26', u'_context_roles': [u'admin'], u'args': {u'request_spec': {u'volume_properties': {u'status': u'creating', u'volume_type_id': None, u'user_id': u'f3b53899ff5c4233a53c8509ad58bfc1', u'display_name': u'vol1', u'availability_zone': u'nova', u'reservations': [u'e0250fe0-c5c7-4da7-8a15-e7dace340475', u'9600db93-8615-4d0a-a4dc-f5dfc6b9b91f'], u'snapshot_id': None, u'attach_status': u'detached', u'display_description': None, u'volume_metadata': [], u'source_volid': None, u'volume_admin_metadata': [], u'encryption_key_id': None, u'project_id': u'2a829d27178843108bc9ca279463634a', u'id': u'545f8321-4be0-4f3b-a502-bd2811947b07', u'size': 1, u'metadata': {}}, u'volume_type': {}, u'image_id': None, u'snapshot_id': None, u'source_volid': None, u'volume_id': u'545f8321-4be0-4f3b-a502-bd2811947b07', u'resource_properties': {u'status': u'creating', u'volume_type_id': None, u'display_name': u'vol1', u'availability_zone': u'nova', u'reservations': [u'e0250fe0-c5c7-4da7-8a15-e7dace340475', u'9600db93-8615-4d0a-a4dc-f5dfc6b9b91f'], u'volume_admin_metadata': [], u'attach_status': u'detached', u'source_volid': None, u'metadata': {}, u'user_id': u'f3b53899ff5c4233a53c8509ad58bfc1', u'volume_metadata': [], u'display_description': None, u'snapshot_id': None, u'encryption_key_id': None, u'project_id': u'2a829d27178843108bc9ca279463634a', u'id': u'545f8321-4be0-4f3b-a502-bd2811947b07', u'size': 1}}, u'allow_reschedule': True, u'filter_properties': {u'config_options': {}, u'user_id': u'f3b53899ff5c4233a53c8509ad58bfc1', u'availability_zone': u'nova', u'volume_type': {}, u'request_spec': {u'volume_properties': {u'status': u'creating', u'volume_type_id': None, u'user_id': u'f3b53899ff5c4233a53c8509ad58bfc1', u'availability_zone': u'nova', u'reservations': [u'e0250fe0-c5c7-4da7-8a15-e7dace340475', u'9600db93-8615-4d0a-a4dc-f5dfc6b9b91f'], u'volume_admin_metadata': [], u'attach_status': u'detached', u'display_description': None, u'metadata': {}, u'volume_metadata': [], u'source_volid': None, u'snapshot_id': None, u'encryption_key_id': None, u'project_id': u'2a829d27178843108bc9ca279463634a', u'id': u'545f8321-4be0-4f3b-a502-bd2811947b07', u'size': 1, u'display_name': u'vol1'}, u'source_volid': None, u'image_id': None, u'snapshot_id': None, u'volume_type': {}, u'volume_id': u'545f8321-4be0-4f3b-a502-bd2811947b07', u'resource_properties': {u'status': u'creating', u'volume_type_id': None, u'display_name': u'vol1', u'volume_metadata': [], u'reservations': [u'e0250fe0-c5c7-4da7-8a15-e7dace340475', u'9600db93-8615-4d0a-a4dc-f5dfc6b9b91f'], u'availability_zone': u'nova', u'attach_status': u'detached', u'source_volid': None, u'snapshot_id': None, u'encryption_key_id': None, u'display_description': None, u'volume_admin_metadata': [], u'user_id': u'f3b53899ff5c4233a53c8509ad58bfc1', u'project_id': u'2a829d27178843108bc9ca279463634a', u'id': u'545f8321-4be0-4f3b-a502-bd2811947b07', u'size': 1, u'metadata': {}}}, u'qos_specs': None, u'retry': {u'num_attempts': 3, u'hosts': [u'jhenner-node-7v0.novalocal', u'jhenner-node-7v0.novalocal', u'jhenner-node-7v0.novalocal']}, u'size': 1, u'resource_type': {}, u'metadata': {}}, u'source_volid': None, u'image_id': None, u'snapshot_id': None, u'volume_id': u'545f8321-4be0-4f3b-a502-bd2811947b07'}, u'_unique_id': u'0e596571565c4bf69baca59be52c389e', u'_context_project_name': u'admin', u'_context_read_deleted': u'no', u'_context_user_identity': u'f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -', u'_context_tenant': u'2a829d27178843108bc9ca279463634a', u'_context_project_id': u'2a829d27178843108bc9ca279463634a', u'_context_user_domain': None} _safe_log /usr/lib/python2.7/site-packages/oslo/messaging/_drivers/common.py:290
>2014-07-18 11:11:55.778 22666 DEBUG oslo.messaging._drivers.amqp [-] unpacked context: {'tenant': u'2a829d27178843108bc9ca279463634a', 'domain': None, 'project_name': u'admin', 'user_id': u'f3b53899ff5c4233a53c8509ad58bfc1', 'roles': [u'admin'], 'user_identity': u'f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -', 'project_domain': None, 'timestamp': u'2014-07-18T15:11:52.202633', 'auth_token': '<SANITIZED>', 'remote_address': u'172.16.40.26', 'quota_class': None, 'user_domain': None, 'is_admin': True, 'user': u'f3b53899ff5c4233a53c8509ad58bfc1', 'service_catalog': [{u'endpoints_links': [], u'endpoints': [{u'adminURL': u'http://172.16.40.26:8774/v2/2a829d27178843108bc9ca279463634a', u'region': u'RegionOne', u'publicURL': u'http://172.16.40.26:8774/v2/2a829d27178843108bc9ca279463634a', u'internalURL': u'http://172.16.40.26:8774/v2/2a829d27178843108bc9ca279463634a', u'id': u'25845b4039334dc68a5ad4893d3ffabe'}], u'type': u'compute', u'name': u'nova'}], 'request_id': u'req-ae13d392-afb7-4096-89d6-cc60e934d4bb', 'project_id': u'2a829d27178843108bc9ca279463634a', 'read_deleted': u'no'} _safe_log /usr/lib/python2.7/site-packages/oslo/messaging/_drivers/common.py:290
>2014-07-18 11:11:55.780 22666 WARNING cinder.context [-] Arguments dropped when creating context: {'user': u'f3b53899ff5c4233a53c8509ad58bfc1', 'tenant': u'2a829d27178843108bc9ca279463634a', 'user_identity': u'f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -'}
>2014-07-18 11:11:55.782 22666 DEBUG stevedore.extension [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] found extension EntryPoint.parse('default = taskflow.engines.action_engine.engine:SingleThreadedActionEngine') _load_plugins /usr/lib/python2.7/site-packages/stevedore/extension.py:156
>2014-07-18 11:11:55.785 22666 DEBUG stevedore.extension [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] found extension EntryPoint.parse('serial = taskflow.engines.action_engine.engine:SingleThreadedActionEngine') _load_plugins /usr/lib/python2.7/site-packages/stevedore/extension.py:156
>2014-07-18 11:11:55.786 22666 DEBUG stevedore.extension [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] found extension EntryPoint.parse('parallel = taskflow.engines.action_engine.engine:MultiThreadedActionEngine') _load_plugins /usr/lib/python2.7/site-packages/stevedore/extension.py:156
>2014-07-18 11:11:55.787 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] Translated 'cinder.volume.flows.manager.create_volume.ExtractVolumeRefTask;volume:create==1.0' into a graph: wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:55
>2014-07-18 11:11:55.788 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Name: T:cinder.volume.flows.manager.create_volume.ExtractVolumeRefTask;volume:create==1.0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.789 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Type: DiGraph wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.790 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Frozen: False wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.790 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Nodes: 1 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.791 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]    - cinder.volume.flows.manager.create_volume.ExtractVolumeRefTask;volume:create==1.0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.792 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Edges: 0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.792 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Density: 0.000 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.793 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Cycles: 0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.794 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] Translated 'cinder.volume.flows.manager.create_volume.OnFailureRescheduleTask;volume:create==1.0' into a graph: wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:55
>2014-07-18 11:11:55.796 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Name: T:cinder.volume.flows.manager.create_volume.OnFailureRescheduleTask;volume:create==1.0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.797 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Type: DiGraph wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.797 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Frozen: False wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.798 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Nodes: 1 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.799 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]    - cinder.volume.flows.manager.create_volume.OnFailureRescheduleTask;volume:create==1.0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.799 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Edges: 0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.800 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Density: 0.000 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.801 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Cycles: 0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.802 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] Translated 'cinder.volume.flows.manager.create_volume.ExtractVolumeSpecTask;volume:create==1.0' into a graph: wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:55
>2014-07-18 11:11:55.803 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Name: T:cinder.volume.flows.manager.create_volume.ExtractVolumeSpecTask;volume:create==1.0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.804 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Type: DiGraph wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.804 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Frozen: False wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.805 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Nodes: 1 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.806 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]    - cinder.volume.flows.manager.create_volume.ExtractVolumeSpecTask;volume:create==1.0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.807 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Edges: 0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.808 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Density: 0.000 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.809 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Cycles: 0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.810 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] Translated 'cinder.volume.flows.manager.create_volume.NotifyVolumeActionTask;volume:create, create.start==1.0' into a graph: wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:55
>2014-07-18 11:11:55.811 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Name: T:cinder.volume.flows.manager.create_volume.NotifyVolumeActionTask;volume:create, create.start==1.0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.812 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Type: DiGraph wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.812 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Frozen: False wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.813 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Nodes: 1 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.814 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]    - cinder.volume.flows.manager.create_volume.NotifyVolumeActionTask;volume:create, create.start==1.0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.815 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Edges: 0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.816 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Density: 0.000 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.816 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Cycles: 0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.818 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] Translated 'cinder.volume.flows.manager.create_volume.CreateVolumeFromSpecTask;volume:create==1.0' into a graph: wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:55
>2014-07-18 11:11:55.820 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Name: T:cinder.volume.flows.manager.create_volume.CreateVolumeFromSpecTask;volume:create==1.0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.825 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Type: DiGraph wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.826 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Frozen: False wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.826 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Nodes: 1 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.827 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]    - cinder.volume.flows.manager.create_volume.CreateVolumeFromSpecTask;volume:create==1.0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.828 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Edges: 0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.829 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Density: 0.000 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.830 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Cycles: 0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.831 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] Translated 'cinder.volume.flows.manager.create_volume.CreateVolumeOnFinishTask;volume:create, create.end==1.0' into a graph: wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:55
>2014-07-18 11:11:55.832 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Name: T:cinder.volume.flows.manager.create_volume.CreateVolumeOnFinishTask;volume:create, create.end==1.0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.833 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Type: DiGraph wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.835 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Frozen: False wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.836 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Nodes: 1 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.837 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]    - cinder.volume.flows.manager.create_volume.CreateVolumeOnFinishTask;volume:create, create.end==1.0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.838 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Edges: 0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.839 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Density: 0.000 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.839 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Cycles: 0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.841 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] Translated 'taskflow.patterns.linear_flow.Flow: volume_create_manager; 6' into a graph: wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:55
>2014-07-18 11:11:55.843 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Name: F:volume_create_manager wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.844 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Type: DiGraph wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.845 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Frozen: False wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.845 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Nodes: 6 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.846 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]    - cinder.volume.flows.manager.create_volume.ExtractVolumeSpecTask;volume:create==1.0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.847 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]    - cinder.volume.flows.manager.create_volume.ExtractVolumeRefTask;volume:create==1.0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.848 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]    - cinder.volume.flows.manager.create_volume.CreateVolumeOnFinishTask;volume:create, create.end==1.0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.850 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]    - cinder.volume.flows.manager.create_volume.OnFailureRescheduleTask;volume:create==1.0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.851 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]    - cinder.volume.flows.manager.create_volume.NotifyVolumeActionTask;volume:create, create.start==1.0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.852 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]    - cinder.volume.flows.manager.create_volume.CreateVolumeFromSpecTask;volume:create==1.0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.852 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Edges: 5 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.853 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]    cinder.volume.flows.manager.create_volume.ExtractVolumeSpecTask;volume:create==1.0 -> cinder.volume.flows.manager.create_volume.NotifyVolumeActionTask;volume:create, create.start==1.0 ({'flatten': True}) wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.854 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]    cinder.volume.flows.manager.create_volume.ExtractVolumeRefTask;volume:create==1.0 -> cinder.volume.flows.manager.create_volume.OnFailureRescheduleTask;volume:create==1.0 ({'flatten': True}) wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.855 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]    cinder.volume.flows.manager.create_volume.OnFailureRescheduleTask;volume:create==1.0 -> cinder.volume.flows.manager.create_volume.ExtractVolumeSpecTask;volume:create==1.0 ({'flatten': True}) wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.856 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]    cinder.volume.flows.manager.create_volume.NotifyVolumeActionTask;volume:create, create.start==1.0 -> cinder.volume.flows.manager.create_volume.CreateVolumeFromSpecTask;volume:create==1.0 ({'flatten': True}) wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.857 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]    cinder.volume.flows.manager.create_volume.CreateVolumeFromSpecTask;volume:create==1.0 -> cinder.volume.flows.manager.create_volume.CreateVolumeOnFinishTask;volume:create, create.end==1.0 ({'flatten': True}) wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.857 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Density: 0.167 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.858 22666 DEBUG taskflow.utils.flow_utils [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -]  Cycles: 0 wrapper /usr/lib/python2.7/site-packages/taskflow/utils/flow_utils.py:58
>2014-07-18 11:11:55.928 22666 DEBUG oslo.messaging._drivers.amqp [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] UNIQUE_ID is a8ec1e2d49bd439b87811bf4605dfe35. _add_unique_id /usr/lib/python2.7/site-packages/oslo/messaging/_drivers/amqp.py:338
>2014-07-18 11:11:55.943 22666 INFO cinder.volume.flows.manager.create_volume [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] Volume 545f8321-4be0-4f3b-a502-bd2811947b07: being created using CreateVolumeFromSpecTask._create_raw_volume with specification: {'status': u'error', 'volume_size': 1, 'volume_name': u'volume-545f8321-4be0-4f3b-a502-bd2811947b07'}
>2014-07-18 11:11:56.617 22666 DEBUG cinder.volume.drivers.vmware.api [-] Checking if the current session: 521110c6-5abc-2e80-b38b-11c9723f809b is active. _is_current_session_active /usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/api.py:260
>2014-07-18 11:11:57.188 22666 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>521110c6-5abc-2e80-b38b-11c9723f809b</ns0:sessionID>
>         <ns0:userName>root</ns0:userName>
>      </ns0:SessionIsActive>
>   </ns1:Body>
></SOAP-ENV:Envelope>
>2014-07-18 11:11:57.190 22666 ERROR cinder.openstack.common.loopingcall [-] in dynamic looping call
>2014-07-18 11:11:57.190 22666 TRACE cinder.openstack.common.loopingcall Traceback (most recent call last):
>2014-07-18 11:11:57.190 22666 TRACE cinder.openstack.common.loopingcall   File "/usr/lib/python2.7/site-packages/cinder/openstack/common/loopingcall.py", line 123, in _inner
>2014-07-18 11:11:57.190 22666 TRACE cinder.openstack.common.loopingcall     idle = self.f(*self.args, **self.kw)
>2014-07-18 11:11:57.190 22666 TRACE cinder.openstack.common.loopingcall   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/api.py", line 82, in _func
>2014-07-18 11:11:57.190 22666 TRACE cinder.openstack.common.loopingcall     raise excep
>2014-07-18 11:11:57.190 22666 TRACE cinder.openstack.common.loopingcall VimFaultException: Server raised fault: 'The session is not authenticated.'
>2014-07-18 11:11:57.190 22666 TRACE cinder.openstack.common.loopingcall 
>2014-07-18 11:11:57.192 22666 DEBUG cinder.volume.flows.manager.create_volume [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] Updating volume 545f8321-4be0-4f3b-a502-bd2811947b07 with {'status': 'creating', 'scheduled_at': datetime.datetime(2014, 7, 18, 15, 11, 57, 192553)}. _pre_reschedule /usr/lib/python2.7/site-packages/cinder/volume/flows/manager/create_volume.py:138
>2014-07-18 11:11:57.215 22666 DEBUG cinder.volume.flows.manager.create_volume [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] Volume 545f8321-4be0-4f3b-a502-bd2811947b07: re-scheduling SchedulerAPI.create_volume attempt 3 due to Server raised fault: 'The session is not authenticated.' _reschedule /usr/lib/python2.7/site-packages/cinder/volume/flows/manager/create_volume.py:106
>2014-07-18 11:11:57.216 22666 DEBUG oslo.messaging._drivers.amqp [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] UNIQUE_ID is 30f64bab80664195b024d8aca21d144b. _add_unique_id /usr/lib/python2.7/site-packages/oslo/messaging/_drivers/amqp.py:338
>2014-07-18 11:11:57.220 22666 DEBUG cinder.volume.flows.manager.create_volume [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] Volume 545f8321-4be0-4f3b-a502-bd2811947b07: re-scheduled _post_reschedule /usr/lib/python2.7/site-packages/cinder/volume/flows/manager/create_volume.py:120
>2014-07-18 11:11:57.221 22666 DEBUG cinder.volume.flows.common [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] Updating volume: 545f8321-4be0-4f3b-a502-bd2811947b07 with {'status': 'error'} due to: ??? error_out_volume /usr/lib/python2.7/site-packages/cinder/volume/flows/common.py:87
>2014-07-18 11:11:57.252 22666 ERROR cinder.volume.flows.manager.create_volume [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] Volume 545f8321-4be0-4f3b-a502-bd2811947b07: create failed
>2014-07-18 11:11:57.253 22666 ERROR oslo.messaging.rpc.dispatcher [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] Exception during message handling: Server raised fault: 'The session is not authenticated.'
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher Traceback (most recent call last):
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 133, in _dispatch_and_reply
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher     incoming.message))
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 176, in _dispatch
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher     return self._do_dispatch(endpoint, method, ctxt, args)
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 122, in _do_dispatch
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher     result = getattr(endpoint, method)(ctxt, **new_args)
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/volume/manager.py", line 363, in create_volume
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher     _run_flow()
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/volume/manager.py", line 356, in _run_flow
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher     flow_engine.run()
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/taskflow/utils/lock_utils.py", line 51, in wrapper
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher     return f(*args, **kwargs)
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/taskflow/engines/action_engine/engine.py", line 118, in run
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher     self._run()
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/taskflow/engines/action_engine/engine.py", line 128, in _run
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher     self._revert(misc.Failure())
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/taskflow/engines/action_engine/engine.py", line 81, in _revert
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher     misc.Failure.reraise_if_any(failures.values())
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/taskflow/utils/misc.py", line 487, in reraise_if_any
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher     failures[0].reraise()
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/taskflow/utils/misc.py", line 494, in reraise
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher     six.reraise(*self._exc_info)
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/taskflow/engines/action_engine/executor.py", line 36, in _execute_task
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher     result = task.execute(**arguments)
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/volume/flows/manager/create_volume.py", line 594, in execute
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher     **volume_spec)
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/volume/flows/manager/create_volume.py", line 564, in _create_raw_volume
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher     return self.driver.create_volume(volume_ref)
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/vmdk.py", line 262, in create_volume
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher     self._verify_volume_creation(volume)
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/vmdk.py", line 246, in _verify_volume_creation
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher     self._select_ds_for_volume(volume)
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/vmdk.py", line 468, in _select_ds_for_volume
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher     retrv_result = self.volumeops.get_hosts()
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/volumeops.py", line 121, in get_hosts
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher     'HostSystem', self._max_objects)
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/api.py", line 252, in invoke_api
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher     return _invoke_api(module, method, *args, **kwargs)
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/api.py", line 89, in func
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher     return timer.wait()
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/eventlet/event.py", line 116, in wait
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher     return hubs.get_hub().switch()
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/eventlet/hubs/hub.py", line 187, in switch
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher     return self.greenlet.switch()
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/openstack/common/loopingcall.py", line 123, in _inner
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher     idle = self.f(*self.args, **self.kw)
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/api.py", line 82, in _func
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher     raise excep
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher VimFaultException: Server raised fault: 'The session is not authenticated.'
>2014-07-18 11:11:57.253 22666 TRACE oslo.messaging.rpc.dispatcher 
>2014-07-18 11:11:57.255 22666 ERROR oslo.messaging._drivers.common [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] Returning exception Server raised fault: 'The session is not authenticated.' to caller
>2014-07-18 11:11:57.255 22666 ERROR oslo.messaging._drivers.common [req-ae13d392-afb7-4096-89d6-cc60e934d4bb f3b53899ff5c4233a53c8509ad58bfc1 2a829d27178843108bc9ca279463634a - - -] ['Traceback (most recent call last):\n', '  File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 133, in _dispatch_and_reply\n    incoming.message))\n', '  File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 176, in _dispatch\n    return self._do_dispatch(endpoint, method, ctxt, args)\n', '  File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 122, in _do_dispatch\n    result = getattr(endpoint, method)(ctxt, **new_args)\n', '  File "/usr/lib/python2.7/site-packages/cinder/volume/manager.py", line 363, in create_volume\n    _run_flow()\n', '  File "/usr/lib/python2.7/site-packages/cinder/volume/manager.py", line 356, in _run_flow\n    flow_engine.run()\n', '  File "/usr/lib/python2.7/site-packages/taskflow/utils/lock_utils.py", line 51, in wrapper\n    return f(*args, **kwargs)\n', '  File "/usr/lib/python2.7/site-packages/taskflow/engines/action_engine/engine.py", line 118, in run\n    self._run()\n', '  File "/usr/lib/python2.7/site-packages/taskflow/engines/action_engine/engine.py", line 128, in _run\n    self._revert(misc.Failure())\n', '  File "/usr/lib/python2.7/site-packages/taskflow/engines/action_engine/engine.py", line 81, in _revert\n    misc.Failure.reraise_if_any(failures.values())\n', '  File "/usr/lib/python2.7/site-packages/taskflow/utils/misc.py", line 487, in reraise_if_any\n    failures[0].reraise()\n', '  File "/usr/lib/python2.7/site-packages/taskflow/utils/misc.py", line 494, in reraise\n    six.reraise(*self._exc_info)\n', '  File "/usr/lib/python2.7/site-packages/taskflow/engines/action_engine/executor.py", line 36, in _execute_task\n    result = task.execute(**arguments)\n', '  File "/usr/lib/python2.7/site-packages/cinder/volume/flows/manager/create_volume.py", line 594, in execute\n    **volume_spec)\n', '  File "/usr/lib/python2.7/site-packages/cinder/volume/flows/manager/create_volume.py", line 564, in _create_raw_volume\n    return self.driver.create_volume(volume_ref)\n', '  File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/vmdk.py", line 262, in create_volume\n    self._verify_volume_creation(volume)\n', '  File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/vmdk.py", line 246, in _verify_volume_creation\n    self._select_ds_for_volume(volume)\n', '  File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/vmdk.py", line 468, in _select_ds_for_volume\n    retrv_result = self.volumeops.get_hosts()\n', '  File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/volumeops.py", line 121, in get_hosts\n    \'HostSystem\', self._max_objects)\n', '  File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/api.py", line 252, in invoke_api\n    return _invoke_api(module, method, *args, **kwargs)\n', '  File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/api.py", line 89, in func\n    return timer.wait()\n', '  File "/usr/lib/python2.7/site-packages/eventlet/event.py", line 116, in wait\n    return hubs.get_hub().switch()\n', '  File "/usr/lib/python2.7/site-packages/eventlet/hubs/hub.py", line 187, in switch\n    return self.greenlet.switch()\n', '  File "/usr/lib/python2.7/site-packages/cinder/openstack/common/loopingcall.py", line 123, in _inner\n    idle = self.f(*self.args, **self.kw)\n', '  File "/usr/lib/python2.7/site-packages/cinder/volume/drivers/vmware/api.py", line 82, in _func\n    raise excep\n', "VimFaultException: Server raised fault: 'The session is not authenticated.'\n"]
>2014-07-18 11:12:01.817 22666 DEBUG cinder.openstack.common.periodic_task [-] Running periodic task VolumeManager._publish_service_capabilities run_periodic_tasks /usr/lib/python2.7/site-packages/cinder/openstack/common/periodic_task.py:178
>2014-07-18 11:12:01.817 22666 DEBUG cinder.manager [-] Notifying Schedulers of capabilities ... _publish_service_capabilities /usr/lib/python2.7/site-packages/cinder/manager.py:128
>2014-07-18 11:12:01.818 22666 DEBUG oslo.messaging._drivers.amqp [-] UNIQUE_ID is 9fd088f81284472ca376275c15b9dc61. _add_unique_id /usr/lib/python2.7/site-packages/oslo/messaging/_drivers/amqp.py:338
>2014-07-18 11:12:01.821 22666 DEBUG cinder.openstack.common.periodic_task [-] Running periodic task VolumeManager._report_driver_status run_periodic_tasks /usr/lib/python2.7/site-packages/cinder/openstack/common/periodic_task.py:178
>2014-07-18 11:12:01.821 22666 INFO cinder.volume.manager [-] Updating volume status

Actions: View

Attachments on bug 1121191: 919121