Concurrent instance creation using cinder 3par iSCSI volumes are failing

Bug #1642945 reported by Vijay Ladani
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Cinder
Fix Released
Undecided
Vijay Ladani

Bug Description

When running a script to create instance concurrently 10 times, some of the instances are going in ERROR states.

script:
-------
for i in `seq 10`
do
  cinder create --image-id $IMG --name XXX-$i --volume-type Standard 5 &
done

cinder-volume.log contains errors:
---------------------------------
2016-11-14 14:06:09.739 29418 ERROR os_brick.initiator.connector [req-f7c55cc7-7c39-45a3-84fd-7fb3b83b6aa2 06e0eae87e7e4916879f8b0fa9ced14c c2022161a5664e79b74b66b0c9119dda] Could not login to any iSCSI portal.
2016-11-14 14:06:09.740 29418 DEBUG oslo_concurrency.lockutils [req-f7c55cc7-7c39-45a3-84fd-7fb3b83b6aa2 06e0eae87e7e4916879f8b0fa9ced14c c2022161a5664e79b74b66b0c9119dda] Lock "connect_volume" released by "os_brick.initiator.connector.connect_volume" :: held 5.082s inner /opt/stack/venv/nova-20161014T013009Z/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [req-f7c55cc7-7c39-45a3-84fd-7fb3b83b6aa2 06e0eae87e7e4916879f8b0fa9ced14c c2022161a5664e79b74b66b0c9119dda] [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] Instance failed to spawn
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] Traceback (most recent call last):
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] File "/opt/stack/venv/nova-20161014T013009Z/lib/python2.7/site-packages/nova/compute/manager.py", line 2222, in _build_resources
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] yield resources
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] File "/opt/stack/venv/nova-20161014T013009Z/lib/python2.7/site-packages/nova/compute/manager.py", line 2068, in _build_and_run_instance
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] block_device_info=block_device_info)
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] File "/opt/stack/venv/nova-20161014T013009Z/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 2779, in spawn
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] write_to_disk=True)
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] File "/opt/stack/venv/nova-20161014T013009Z/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4768, in _get_guest_xml
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] context)
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] File "/opt/stack/venv/nova-20161014T013009Z/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4615, in _get_guest_config
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] flavor, guest.os_type)
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] File "/opt/stack/venv/nova-20161014T013009Z/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 3688, in _get_guest_storage_config
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] self._connect_volume(connection_info, info)
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] File "/opt/stack/venv/nova-20161014T013009Z/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 1276, in _connect_volume
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] vol_driver.connect_volume(connection_info, disk_info)
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] File "/opt/stack/venv/nova-20161014T013009Z/lib/python2.7/site-packages/nova/virt/libvirt/volume/iscsi.py", line 87, in connect_volume
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] device_info = self.connector.connect_volume(connection_info['data'])
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] File "/opt/stack/venv/nova-20161014T013009Z/lib/python2.7/site-packages/oslo_concurrency/lockutils.py", line 271, in inner
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] return f(*args, **kwargs)
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] File "/opt/stack/venv/nova-20161014T013009Z/lib/python2.7/site-packages/os_brick/initiator/connector.py", line 846, in connect_volume
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] connection_properties)
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] File "/opt/stack/venv/nova-20161014T013009Z/lib/python2.7/site-packages/os_brick/initiator/connector.py", line 675, in _get_potential_volume_paths
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] raise exception.FailedISCSITargetPortalLogin(message=msg)
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] FailedISCSITargetPortalLogin: Could not login to any iSCSI portal.
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a]

nova-compute.log
--------------------
2016-11-14 14:06:09.739 29418 ERROR os_brick.initiator.connector [req-f7c55cc7-7c39-45a3-84fd-7fb3b83b6aa2 06e0eae87e7e4916879f8b0fa9ced14c c2022161a5664e79b74b66b0c9119dda] Could not login to any iSCSI portal.
2016-11-14 14:06:09.740 29418 DEBUG oslo_concurrency.lockutils [req-f7c55cc7-7c39-45a3-84fd-7fb3b83b6aa2 06e0eae87e7e4916879f8b0fa9ced14c c2022161a5664e79b74b66b0c9119dda] Lock "connect_volume" released by "os_brick.initiator.connector.connect_volume" :: held 5.082s inner /opt/stack/venv/nova-20161014T013009Z/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:282
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [req-f7c55cc7-7c39-45a3-84fd-7fb3b83b6aa2 06e0eae87e7e4916879f8b0fa9ced14c c2022161a5664e79b74b66b0c9119dda] [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] Instance failed to spawn
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] Traceback (most recent call last):
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] File "/opt/stack/venv/nova-20161014T013009Z/lib/python2.7/site-packages/nova/compute/manager.py", line 2222, in _build_resources
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] yield resources
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] File "/opt/stack/venv/nova-20161014T013009Z/lib/python2.7/site-packages/nova/compute/manager.py", line 2068, in _build_and_run_instance
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] block_device_info=block_device_info)
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] File "/opt/stack/venv/nova-20161014T013009Z/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 2779, in spawn
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] write_to_disk=True)
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] File "/opt/stack/venv/nova-20161014T013009Z/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4768, in _get_guest_xml
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] context)
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] File "/opt/stack/venv/nova-20161014T013009Z/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4615, in _get_guest_config
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] flavor, guest.os_type)
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] File "/opt/stack/venv/nova-20161014T013009Z/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 3688, in _get_guest_storage_config
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] self._connect_volume(connection_info, info)
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] File "/opt/stack/venv/nova-20161014T013009Z/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 1276, in _connect_volume
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] vol_driver.connect_volume(connection_info, disk_info)
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] File "/opt/stack/venv/nova-20161014T013009Z/lib/python2.7/site-packages/nova/virt/libvirt/volume/iscsi.py", line 87, in connect_volume
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] device_info = self.connector.connect_volume(connection_info['data'])
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] File "/opt/stack/venv/nova-20161014T013009Z/lib/python2.7/site-packages/oslo_concurrency/lockutils.py", line 271, in inner
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] return f(*args, **kwargs)
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] File "/opt/stack/venv/nova-20161014T013009Z/lib/python2.7/site-packages/os_brick/initiator/connector.py", line 846, in connect_volume
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] connection_properties)
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] File "/opt/stack/venv/nova-20161014T013009Z/lib/python2.7/site-packages/os_brick/initiator/connector.py", line 675, in _get_potential_volume_paths
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] raise exception.FailedISCSITargetPortalLogin(message=msg)
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a] FailedISCSITargetPortalLogin: Could not login to any iSCSI portal.
2016-11-14 14:06:09.740 29418 ERROR nova.compute.manager [instance: 29dd105a-6b4b-47f8-91b3-985efc61334a]

Changed in cinder:
assignee: nobody → Vijay Ladani (vijay-ladani)
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to cinder (stable/mitaka)

Fix proposed to branch: stable/mitaka
Review: https://review.openstack.org/400207

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Change abandoned on cinder (stable/mitaka)

Change abandoned by Vijay Ladani (<email address hidden>) on branch: stable/mitaka
Review: https://review.openstack.org/400207
Reason: Creating new patch to master and then will back port to stable/mitaka

Revision history for this message
OpenStack Infra (hudson-openstack) wrote :

Change abandoned by Vijay Ladani (<email address hidden>) on branch: stable/mitaka
Review: https://review.openstack.org/400207

Changed in cinder:
status: New → In Progress
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to cinder (master)

Fix proposed to branch: master
Review: https://review.openstack.org/400511

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to cinder (stable/newton)

Fix proposed to branch: stable/newton
Review: https://review.openstack.org/403510

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to cinder (stable/mitaka)

Fix proposed to branch: stable/mitaka
Review: https://review.openstack.org/403564

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Change abandoned on cinder (stable/mitaka)

Change abandoned by Vijay Ladani (<email address hidden>) on branch: stable/mitaka
Review: https://review.openstack.org/400207
Reason: Not able to make this patch as cherry pick.

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to cinder (master)

Reviewed: https://review.openstack.org/400511
Committed: https://git.openstack.org/cgit/openstack/cinder/commit/?id=9b0c5c4318d3c348ce185a3f4dd94f9e803bf264
Submitter: Jenkins
Branch: master

commit 9b0c5c4318d3c348ce185a3f4dd94f9e803bf264
Author: Vijay Ladani <email address hidden>
Date: Mon Nov 21 20:31:08 2016 -0800

    HPE3PAR: handle conflict in iscsi host create

    One of the step in creating iSCSI VLUN is to create a host on array.
    If there are simultaneous requests comming on 3par array for creating
    same host, hpe3parclient creates host for first request and returns
    HTTP 409 conflict error for others, with error code 73, message "host
    WWN/iSCSI name already used by another host". This was not handled by
    3PAR iscsi driver and the HTTP exception would propagate up to volume
    manager where it would log it. This patch addresses issue by catching
    this exception and reusing the same host.

    Change-Id: I102409539c9a691c1816a342163dd049855f57da
    Closes-Bug: #1642945

Changed in cinder:
status: In Progress → Fix Released
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to cinder (stable/newton)

Reviewed: https://review.openstack.org/403510
Committed: https://git.openstack.org/cgit/openstack/cinder/commit/?id=f9519cca0562543c20ef9fbb23b47291d7e25db1
Submitter: Jenkins
Branch: stable/newton

commit f9519cca0562543c20ef9fbb23b47291d7e25db1
Author: Vijay Ladani <email address hidden>
Date: Mon Nov 21 20:31:08 2016 -0800

    HPE3PAR: handle conflict in iscsi host create

    One of the step in creating iSCSI VLUN is to create a host on array.
    If there are simultaneous requests comming on 3par array for creating
    same host, hpe3parclient creates host for first request and returns
    HTTP 409 conflict error for others, with error code 73, message "host
    WWN/iSCSI name already used by another host". This was not handled by
    3PAR iscsi driver and the HTTP exception would propagate up to volume
    manager where it would log it. This patch addresses issue by catching
    this exception and reusing the same host.

    Closes-Bug: #1642945
    (cherry picked from commit 9b0c5c4318d3c348ce185a3f4dd94f9e803bf264)

    Change-Id: I102409539c9a691c1816a342163dd049855f57da

tags: added: in-stable-newton
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix included in openstack/cinder 10.0.0.0b2

This issue was fixed in the openstack/cinder 10.0.0.0b2 development milestone.

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to cinder (driverfixes/mitaka)

Fix proposed to branch: driverfixes/mitaka
Review: https://review.openstack.org/412281

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to cinder (driverfixes/mitaka)

Reviewed: https://review.openstack.org/412281
Committed: https://git.openstack.org/cgit/openstack/cinder/commit/?id=6d7ec769e7b7981526c5850044023b4cab15634c
Submitter: Jenkins
Branch: driverfixes/mitaka

commit 6d7ec769e7b7981526c5850044023b4cab15634c
Author: Vijay Ladani <email address hidden>
Date: Sun Dec 18 20:43:17 2016 -0800

    HPE3PAR: handle conflict in iscsi host create

    One of the step in creating iSCSI VLUN is to create a host on array.
    If there are simultaneous requests comming on 3par array for creating
    same host, hpe3parclient creates host for first request and returns
    HTTP 409 conflict error for others, with error code 73, message "host
    WWN/iSCSI name already used by another host". This was not handled by
    3PAR iscsi driver and the HTTP exception would propagate up to volume
    manager where it would log it. This patch addresses issue by catching
    this exception and reusing the same host.

    Closes-Bug: #1642945
    (cherry picked from commit 9b0c5c4318d3c348ce185a3f4dd94f9e803bf264)

    Change-Id: I102409539c9a691c1816a342163dd049855f57da

tags: added: in-driverfixes-mitaka
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix included in openstack/cinder 9.1.1

This issue was fixed in the openstack/cinder 9.1.1 release.

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Change abandoned on cinder (stable/mitaka)

Change abandoned by Vijay Ladani (<email address hidden>) on branch: stable/mitaka
Review: https://review.openstack.org/403564
Reason: Changes moved to driverfixes/mitaka

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.