2014-05-26 22:01:48.158 29433 DEBUG cinder.brick.initiator.connector [req-0e4ee3b0-fb88-4a26-9d94-007c510ecb59 49eb4efb16cb4011949b702faceabeb5 4e16f04973    4a43d3b18467359c1a6d35 - - -] Factory for fibre_channel factory /opt/stack/cinder/cinder/brick/initiator/connector.py:83^M
326 2014-05-26 22:01:48.159 29433 DEBUG cinder.openstack.common.lockutils [req-0e4ee3b0-fb88-4a26-9d94-007c510ecb59 49eb4efb16cb4011949b702faceabeb5 4e16f0497    34a43d3b18467359c1a6d35 - - -] Got semaphore "connect_volume" for method "connect_volume"... inner /opt/stack/cinder/cinder/openstack/common/lockutils.py:    191^M
327 2014-05-26 22:01:48.160 29433 DEBUG cinder.brick.initiator.connector [req-0e4ee3b0-fb88-4a26-9d94-007c510ecb59 49eb4efb16cb4011949b702faceabeb5 4e16f04973    4a43d3b18467359c1a6d35 - - -] execute = <function execute at 0x2590410> connect_volume /opt/stack/cinder/cinder/brick/initiator/connector.py:579^M
328 2014-05-26 22:01:48.160 29433 DEBUG cinder.openstack.common.processutils [req-0e4ee3b0-fb88-4a26-9d94-007c510ecb59 49eb4efb16cb4011949b702faceabeb5 4e16f0    49734a43d3b18467359c1a6d35 - - -] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf systool -c fc_host -v execute /opt/stack/cinder    /cinder/openstack/common/processutils.py:142^M
329 2014-05-26 22:01:48.316 29433 DEBUG cinder.brick.initiator.connector [-] Looking for Fibre Channel dev /dev/disk/by-path/pci-0000:0a:00.1-fc-0x5006016c092    0010b-lun-1 _wait_for_device_discovery /opt/stack/cinder/cinder/brick/initiator/connector.py:620^M
330 2014-05-26 22:01:48.317 29433 DEBUG cinder.brick.initiator.connector [-] Looking for Fibre Channel dev /dev/disk/by-path/pci-0000:0a:00.1-fc-0x50060164092    0010b-lun-1 _wait_for_device_discovery /opt/stack/cinder/cinder/brick/initiator/connector.py:620^M
331 2014-05-26 22:01:48.318 29433 DEBUG cinder.brick.initiator.connector [-] Looking for Fibre Channel dev /dev/disk/by-path/pci-0000:0a:00.0-fc-0x5006016c092    0010b-lun-1 _wait_for_device_discovery /opt/stack/cinder/cinder/brick/initiator/connector.py:620^M
332 2014-05-26 22:01:48.318 29433 DEBUG cinder.brick.initiator.connector [-] Looking for Fibre Channel dev /dev/disk/by-path/pci-0000:0a:00.0-fc-0x50060164092    0010b-lun-1 _wait_for_device_discovery /opt/stack/cinder/cinder/brick/initiator/connector.py:620^M
333 2014-05-26 22:01:48.318 29433 WARNING cinder.brick.initiator.connector [-] Fibre volume not yet found. Will rescan & retry.  Try number: 0^M
334 2014-05-26 22:01:48.319 29433 DEBUG cinder.openstack.common.processutils [-] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf tee     -a /sys/class/scsi_host/host10/scan execute /opt/stack/cinder/cinder/openstack/common/processutils.py:142^M
335 2014-05-26 22:01:48.480 29433 DEBUG cinder.openstack.common.processutils [-] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf tee     -a /sys/class/scsi_host/host9/scan execute /opt/stack/cinder/cinder/openstack/common/processutils.py:142^M
336 2014-05-26 22:01:50.318 29433 DEBUG cinder.brick.initiator.connector [-] Looking for Fibre Channel dev /dev/disk/by-path/pci-0000:0a:00.1-fc-0x5006016c092    0010b-lun-1 _wait_for_device_discovery /opt/stack/cinder/cinder/brick/initiator/connector.py:620^M
337 2014-05-26 22:01:50.319 29433 DEBUG cinder.brick.initiator.connector [-] Looking for Fibre Channel dev /dev/disk/by-path/pci-0000:0a:00.1-fc-0x50060164092    0010b-lun-1 _wait_for_device_discovery /opt/stack/cinder/cinder/brick/initiator/connector.py:620^M
338 2014-05-26 22:01:50.319 29433 DEBUG cinder.brick.initiator.connector [-] Looking for Fibre Channel dev /dev/disk/by-path/pci-0000:0a:00.0-fc-0x5006016c092    0010b-lun-1 _wait_for_device_discovery /opt/stack/cinder/cinder/brick/initiator/connector.py:620^M
339 2014-05-26 22:01:50.319 29433 DEBUG cinder.brick.initiator.connector [-] Looking for Fibre Channel dev /dev/disk/by-path/pci-0000:0a:00.0-fc-0x50060164092    0010b-lun-1 _wait_for_device_discovery /opt/stack/cinder/cinder/brick/initiator/connector.py:620^M
340 2014-05-26 22:01:50.320 29433 WARNING cinder.brick.initiator.connector [-] Fibre volume not yet found. Will rescan & retry.  Try number: 1^M
341 2014-05-26 22:01:50.320 29433 DEBUG cinder.openstack.common.processutils [-] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf tee     -a /sys/class/scsi_host/host10/scan execute /opt/stack/cinder/cinder/openstack/common/processutils.py:142^M
342 2014-05-26 22:01:50.475 29433 DEBUG cinder.openstack.common.processutils [-] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf tee     -a /sys/class/scsi_host/host9/scan execute /opt/stack/cinder/cinder/openstack/common/processutils.py:142^M
343 2014-05-26 22:01:52.319 29433 DEBUG cinder.brick.initiator.connector [-] Looking for Fibre Channel dev /dev/disk/by-path/pci-0000:0a:00.1-fc-0x5006016c092    0010b-lun-1 _wait_for_device_discovery /opt/stack/cinder/cinder/brick/initiator/connector.py:620^M
344 2014-05-26 22:01:52.320 29433 DEBUG cinder.brick.initiator.connector [-] Looking for Fibre Channel dev /dev/disk/by-path/pci-0000:0a:00.1-fc-0x50060164092    0010b-lun-1 _wait_for_device_discovery /opt/stack/cinder/cinder/brick/initiator/connector.py:620^M
345 2014-05-26 22:01:52.320 29433 DEBUG cinder.brick.initiator.connector [-] Looking for Fibre Channel dev /dev/disk/by-path/pci-0000:0a:00.0-fc-0x5006016c092    0010b-lun-1 _wait_for_device_discovery /opt/stack/cinder/cinder/brick/initiator/connector.py:620^M
346 2014-05-26 22:01:52.321 29433 DEBUG cinder.brick.initiator.connector [-] Looking for Fibre Channel dev /dev/disk/by-path/pci-0000:0a:00.0-fc-0x50060164092    0010b-lun-1 _wait_for_device_discovery /opt/stack/cinder/cinder/brick/initiator/connector.py:620^M
347 2014-05-26 22:01:52.321 29433 WARNING cinder.brick.initiator.connector [-] Fibre volume not yet found. Will rescan & retry.  Try number: 2^M
348 2014-05-26 22:01:52.322 29433 DEBUG cinder.openstack.common.processutils [-] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf tee     -a /sys/class/scsi_host/host10/scan execute /opt/stack/cinder/cinder/openstack/common/processutils.py:142^M
349 2014-05-26 22:01:52.473 29433 DEBUG cinder.openstack.common.processutils [-] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf tee     -a /sys/class/scsi_host/host9/scan execute /opt/stack/cinder/cinder/openstack/common/processutils.py:142^M
350 2014-05-26 22:01:54.321 29433 DEBUG cinder.brick.initiator.connector [-] Looking for Fibre Channel dev /dev/disk/by-path/pci-0000:0a:00.1-fc-0x5006016c092    0010b-lun-1 _wait_for_device_discovery /opt/stack/cinder/cinder/brick/initiator/connector.py:620^M
351 2014-05-26 22:01:54.322 29433 DEBUG cinder.brick.initiator.connector [-] Looking for Fibre Channel dev /dev/disk/by-path/pci-0000:0a:00.1-fc-0x50060164092    0010b-lun-1 _wait_for_device_discovery /opt/stack/cinder/cinder/brick/initiator/connector.py:620^M
352 2014-05-26 22:01:54.322 29433 DEBUG cinder.brick.initiator.connector [-] Looking for Fibre Channel dev /dev/disk/by-path/pci-0000:0a:00.0-fc-0x5006016c092    0010b-lun-1 _wait_for_device_discovery /opt/stack/cinder/cinder/brick/initiator/connector.py:620^M
353 2014-05-26 22:01:54.322 29433 DEBUG cinder.brick.initiator.connector [-] Looking for Fibre Channel dev /dev/disk/by-path/pci-0000:0a:00.0-fc-0x50060164092    0010b-lun-1 _wait_for_device_discovery /opt/stack/cinder/cinder/brick/initiator/connector.py:620^M
354 2014-05-26 22:01:54.323 29433 ERROR cinder.brick.initiator.connector [-] Fibre Channel volume device not found.^M
355 2014-05-26 22:01:54.323 29433 ERROR cinder.openstack.common.loopingcall [-] in fixed duration looping call^M
356 2014-05-26 22:01:54.323 29433 TRACE cinder.openstack.common.loopingcall Traceback (most recent call last):^M
357 2014-05-26 22:01:54.323 29433 TRACE cinder.openstack.common.loopingcall   File "/opt/stack/cinder/cinder/openstack/common/loopingcall.py", line 76, in _in    ner^M
358 2014-05-26 22:01:54.323 29433 TRACE cinder.openstack.common.loopingcall     self.f(*self.args, **self.kw)^M
359 2014-05-26 22:01:54.323 29433 TRACE cinder.openstack.common.loopingcall   File "/opt/stack/cinder/cinder/brick/initiator/connector.py", line 631, in _wait    _for_device_discovery^M
360 2014-05-26 22:01:54.323 29433 TRACE cinder.openstack.common.loopingcall     raise exception.NoFibreChannelVolumeDeviceFound()^M
361 2014-05-26 22:01:54.323 29433 TRACE cinder.openstack.common.loopingcall NoFibreChannelVolumeDeviceFound: Unable to find a Fibre Channel volume device.^M
362 2014-05-26 22:01:54.323 29433 TRACE cinder.openstack.common.loopingcall ^M
363 2014-05-26 22:01:54.325 29433 ERROR cinder.volume.flows.manager.create_volume [req-0e4ee3b0-fb88-4a26-9d94-007c510ecb59 49eb4efb16cb4011949b702faceabeb5 4    e16f049734a43d3b18467359c1a6d35 - - -] Failed to copy image f3f000db-72a9-432c-b73d-af82d77766aa to volume: 0e63c998-c941-42cb-86ed-c7431fa8269a, error: U    nable to find a Fibre Channel volume device.^M
364 2014-05-26 22:01:54.328 29433 DEBUG cinder.volume.flows.common [req-0e4ee3b0-fb88-4a26-9d94-007c510ecb59 49eb4efb16cb4011949b702faceabeb5 4e16f049734a43d3    b18467359c1a6d35 - - -] Updating volume: 0e63c998-c941-42cb-86ed-c7431fa8269a with {'status': 'error'} due to: ??? error_out_volume /opt/stack/cinder/cind    er/volume/flows/common.py:87^M
365 2014-05-26 22:01:54.363 29433 ERROR cinder.volume.flows.manager.create_volume [req-0e4ee3b0-fb88-4a26-9d94-007c510ecb59 49eb4efb16cb4011949b702faceabeb5 4    e16f049734a43d3b18467359c1a6d35 - - -] Volume 0e63c998-c941-42cb-86ed-c7431fa8269a: create failed^M
366 2014-05-26 22:01:54.364 29433 ERROR oslo.messaging.rpc.dispatcher [req-0e4ee3b0-fb88-4a26-9d94-007c510ecb59 49eb4efb16cb4011949b702faceabeb5 4e16f049734a4    3d3b18467359c1a6d35 - - -] Exception during message handling: Failed to copy image to volume: Unable to find a Fibre Channel volume device.^M
367 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher Traceback (most recent call last):^M
368 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/oslo.messaging/oslo/messaging/rpc/dispatcher.py", line 133, in _dispa    tch_and_reply^M
369 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher     incoming.message))^M
370 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/oslo.messaging/oslo/messaging/rpc/dispatcher.py", line 176, in _dispa    tch^M
371 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher     return self._do_dispatch(endpoint, method, ctxt, args)^M
372 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/oslo.messaging/oslo/messaging/rpc/dispatcher.py", line 122, in _do_di    spatch^M
373 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher     result = getattr(endpoint, method)(ctxt, **new_args)^M
374 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/cinder/cinder/volume/manager.py", line 335, in create_volume^M
375 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher     _run_flow()^M
376 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/cinder/cinder/volume/manager.py", line 328, in _run_flow^M
377 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher     flow_engine.run()^M
378 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/taskflow/taskflow/utils/lock_utils.py", line 54, in wrapper^M
379 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher     return f(*args, **kwargs)^M
380 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/taskflow/taskflow/engines/action_engine/engine.py", line 96, in run^M
381 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher     self._run()^M
382 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/taskflow/taskflow/engines/action_engine/engine.py", line 111, in _run    ^M
383 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher     misc.Failure.reraise_if_any(failures.values())^M
384 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/taskflow/taskflow/utils/misc.py", line 743, in reraise_if_any^M
385 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher     failures[0].reraise()^M
386 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/taskflow/taskflow/utils/misc.py", line 750, in reraise^M
387 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher     six.reraise(*self._exc_info)^M
388 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/taskflow/taskflow/engines/action_engine/executor.py", line 34, in _ex    ecute_task^M
389 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher     result = task.execute(**arguments)^M
390 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/cinder/cinder/volume/flows/manager/create_volume.py", line 594, in ex    ecute^M
391 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher     **volume_spec)^M
392 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/cinder/cinder/volume/flows/manager/create_volume.py", line 556, in _c    reate_from_image^M
393 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher     image_id, image_location, image_service)^M
394 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/cinder/cinder/volume/flows/manager/create_volume.py", line 470, in _c    opy_image_to_volume^M
395 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher     raise exception.ImageCopyFailure(reason=ex)^M
396 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher ImageCopyFailure: Failed to copy image to volume: Unable to find a Fibre Channel volume     device.^M
397 2014-05-26 22:01:54.364 29433 TRACE oslo.messaging.rpc.dispatcher ^M
398 2014-05-26 22:01:54.366 29433 ERROR oslo.messaging._drivers.common [req-0e4ee3b0-fb88-4a26-9d94-007c510ecb59 49eb4efb16cb4011949b702faceabeb5 4e16f049734a    43d3b18467359c1a6d35 - - -] Returning exception Failed to copy image to volume: Unable to find a Fibre Channel volume device. to caller^M

399 2014-05-26 22:01:54.366 29433 ERROR oslo.messaging._drivers.common [req-0e4ee3b0-fb88-4a26-9d94-007c510ecb59 49eb4efb16cb4011949b702faceabeb5 4e16f049734a    43d3b18467359c1a6d35 - - -] ['Traceback (most recent call last):\n', '  File "/opt/stack/oslo.messaging/oslo/messaging/rpc/dispatcher.py", line 133, in _d    ispatch_and_reply\n    incoming.message))\n', '  File "/opt/stack/oslo.messaging/oslo/messaging/rpc/dispatcher.py", line 176, in _dispatch\n    return sel    f._do_dispatch(endpoint, method, ctxt, args)\n', '  File "/opt/stack/oslo.messaging/oslo/messaging/rpc/dispatcher.py", line 122, in _do_dispatch\n    resu    lt = getattr(endpoint, method)(ctxt, **new_args)\n', '  File "/opt/stack/cinder/cinder/volume/manager.py", line 335, in create_volume\n    _run_flow()\n',     '  File "/opt/stack/cinder/cinder/volume/manager.py", line 328, in _run_flow\n    flow_engine.run()\n', '  File "/opt/stack/taskflow/taskflow/utils/lock_    utils.py", line 54, in wrapper\n    return f(*args, **kwargs)\n', '  File "/opt/stack/taskflow/taskflow/engines/action_engine/engine.py", line 96, in run\    n    self._run()\n', '  File "/opt/stack/taskflow/taskflow/engines/action_engine/engine.py", line 111, in _run\n    misc.Failure.reraise_if_any(failures.v    alues())\n', '  File "/opt/stack/taskflow/taskflow/utils/misc.py", line 743, in reraise_if_any\n    failures[0].reraise()\n', '  File "/opt/stack/taskflow    /taskflow/utils/misc.py", line 750, in reraise\n    six.reraise(*self._exc_info)\n', '  File "/opt/stack/taskflow/taskflow/engines/action_engine/executor.    py", line 34, in _execute_task\n    result = task.execute(**arguments)\n', '  File "/opt/stack/cinder/cinder/volume/flows/manager/create_volume.py", line     594, in execute\n    **volume_spec)\n', '  File "/opt/stack/cinder/cinder/volume/flows/manager/create_volume.py", line 556, in _create_from_image\n    ima    ge_id, image_location, image_service)\n', '  File "/opt/stack/cinder/cinder/volume/flows/manager/create_volume.py", line 470, in _copy_image_to_volume\n        raise exception.ImageCopyFailure(reason=ex)\n', 'ImageCopyFailure: Failed to copy image to volume: Unable to find a Fibre Channel volume device.\n']^M
400 Traceback (most recent call last):^M
401   File "/usr/local/lib/python2.7/dist-packages/eventlet/hubs/poll.py", line 97, in wait^M
402     readers.get(fileno, noop).cb(fileno)^M
403   File "/usr/local/lib/python2.7/dist-packages/eventlet/greenthread.py", line 197, in main^M
404     self._resolve_links()^M
405   File "/usr/local/lib/python2.7/dist-packages/eventlet/greenthread.py", line 212, in _resolve_links^M
406     f(self, *ca, **ckw)^M
407   File "/opt/stack/oslo.messaging/oslo/messaging/_executors/impl_eventlet.py", line 47, in complete^M
408     thread.wait()^M
409   File "/usr/local/lib/python2.7/dist-packages/eventlet/greenthread.py", line 168, in wait^M
410     return self._exit_event.wait()^M
411   File "/usr/local/lib/python2.7/dist-packages/eventlet/event.py", line 120, in wait^M
412     current.throw(*self._exc)^M
413   File "/usr/local/lib/python2.7/dist-packages/eventlet/greenthread.py", line 194, in main^M
414     result = function(*args, **kwargs)^M
415   File "/opt/stack/oslo.messaging/oslo/messaging/rpc/dispatcher.py", line 128, in <lambda>^M
416     yield lambda: self._dispatch_and_reply(incoming)^M
417   File "/opt/stack/oslo.messaging/oslo/messaging/rpc/dispatcher.py", line 143, in _dispatch_and_reply^M
418     incoming.reply(failure=exc_info)^M
419   File "/opt/stack/oslo.messaging/oslo/messaging/_drivers/amqpdriver.py", line 67, in reply^M
420     self._send_reply(conn, reply, failure, log_failure=log_failure)^M
421   File "/opt/stack/oslo.messaging/oslo/messaging/_drivers/amqpdriver.py", line 48, in _send_reply^M
422     log_failure)^M
423   File "/opt/stack/oslo.messaging/oslo/messaging/_drivers/common.py", line 231, in serialize_remote_exception^M
424     json_data = jsonutils.dumps(data)^M
425   File "/opt/stack/oslo.messaging/oslo/messaging/openstack/common/jsonutils.py", line 166, in dumps^M
426     return json.dumps(value, default=default, **kwargs)^M
427   File "/usr/lib/python2.7/json/__init__.py", line 238, in dumps^M
428     **kw).encode(obj)^M
429   File "/usr/lib/python2.7/json/encoder.py", line 201, in encode^M
430     chunks = self.iterencode(o, _one_shot=True)^M
431   File "/usr/lib/python2.7/json/encoder.py", line 264, in iterencode^M
432     return _iterencode(o, 0)^M
433 ValueError: Circular reference detected^M
434 Removing descriptor: 8^M