Not able to create vsphere docker volume (using short volume names) after renaming datastore; running into "IndexError('list index out of range',)"

[shuklanirdesh82]

Short volume name reference: https://github.com/vmware/docker-volume-vsphere/blob/master/docs/misc/VolumeNames.md#short-volume-names

Steps to reproduce:

1. create vsphere docker volume using following command (Let's say we have created photon1 docker host on TestDatastore)

# docker volume create --driver=vmdk --name=MyVol -o size=1gb
MyVol

2. make sure volume is created successfully

[root@promc-2n-dhcp105-97:/var/log/vmware] /usr/lib/vmware/vmdkops/bin/vmdkops_admin.py ls
Volume  Datastore       Created By VM  Created                   Attached To VM  Policy  Capacity  Used     Disk Format  Filesystem Type  Access      Attach As               
------  --------------  -------------  ------------------------  --------------  ------  --------  -------  -----------  ---------------  ----------  ----------------------  
MyVol   TestDatastore  photon2        Tue Dec 13 21:13:49 2016  detached        N/A     1.00GB    39.00MB  N/A          ext4             read-write  independent_persistent

3. rename the datastore which is hosting docker VM i.e. TestDatastore => TestDatastore1
4. wait for some time ~30-60secs to propagate the name changes

[root@promc-2n-dhcp105-97:/var/log/vmware] /usr/lib/vmware/vmdkops/bin/vmdkops_admin.py ls
Volume  Datastore       Created By VM  Created                   Attached To VM  Policy  Capacity  Used     Disk Format  Filesystem Type  Access      Attach As               
------  --------------  -------------  ------------------------  --------------  ------  --------  -------  -----------  ---------------  ----------  ----------------------  
MyVol   **TestDatastore1**  photon2        Tue Dec 13 21:13:49 2016  detached        N/A     1.00GB    39.00MB  N/A          ext4             read-write  independent_persistent

Note: make sure 'Datastore' is reflected correctly i.e. with new name

5. invoke the volume creation command with different volume

# docker volume create --driver=vmdk --name=MyVol1 -o size=1gb
Error response from daemon: create MyVol1: VolumeDriver.Create: dockvols creation failed - Operation not permitted on TestDatastore  <===== driver is still referring to the old name

Expectation: volume creation should not complain if underlying datastore got renamed

from ESX logs:

-----vmdk_ops.log-------
12/13/16 22:59:11 2663252 [Thread-140] [WARNING] dockvols creation failed - Operation not permitted on TestDatastore
12/13/16 22:59:11 2663252 [Thread-140] [INFO   ] executeRequest 'get' completed with ret={u'Error': 'dockvols creation failed - Operation not permitted on TestDatastore'}
12/13/16 22:59:11 2663252 [Thread-141] [WARNING] dockvols creation failed - Operation not permitted on TestDatastore
12/13/16 22:59:11 2663252 [Thread-141] [INFO   ] executeRequest 'create' completed with ret={u'Error': 'dockvols creation failed - Operation not permitted on TestDatastore'}

[govint]

The datastore for the volume ops is obtained from the VM group info in vsi. And that doesn't change when path names change. For example group info
process id:-1
uuid:56 4d 39 2b 3c b8 5a 4a-86 2a 3d f7 a5 90 d9 7e
VC uuid:ee 8c 03 50 ef 71 64 84-4a b4 22 bd 50 4b 64 3e
display name:2
config file path:/vmfs/volumes/523c14b7-e5561042-5e2f-002481aaea6c/2/2.vmx

If the folder "2" is now changed to "2.tmp" the VM data doesn't.

mv 2 2.tmp
ls 2.tmp

2-28419cf8.hlog 2.vmdk 2_1-d286f072022a0891.vmfd stats-1 vmware-37.log vmware-42.log
2-aux.xml 2.vmsd 2_1-flat.vmdk stats-2 vmware-38.log vmware.log
2-b421ee0a.vswp 2.vmx 2_1.vmdk stats-3 vmware-39.log vmx-2-3022122506-1.vswp
2-flat.vmdk 2.vmx.lck stats stats-4 vmware-40.log vmx-2-3022122506-2.vswp
2.nvram

But VM data remains as before
process id:-1
uuid:56 4d 39 2b 3c b8 5a 4a-86 2a 3d f7 a5 90 d9 7e
VC uuid:ee 8c 03 50 ef 71 64 84-4a b4 22 bd 50 4b 64 3e
display name:2
config file path:/vmfs/volumes/523c14b7-e5561042-5e2f-002481aaea6c/2/2.vmx

Which is why the datastore name doesn't change on the next create after a name change. While admin CLI enumerates datastores on the host.

[govint]

One fix for this may be to not use VMM groupInfo to get the datastore and instead use the "datastoreUrl" in the VM config got via VIM api.

[lipingxue]

Verified this has been fixed in top of the master branch. Please see the following detail:

1. create a tenant "tenant1" and associate VM "photon5" to it

[root@localhost:~] /usr/lib/vmware/vmdkops/bin/vmdkops_admin.py tenant create --name=tenant1 --vm-list=photon5
tenant create succeeded

2. create access privilege for this tenant on "datastore1", "datastore1" will be the default datastore for this tenant

[root@localhost:~] /usr/lib/vmware/vmdkops/bin/vmdkops_admin.py tenant access add --name=tenant1 --datastore=datastore1 --allow-create --volume-maxsize=500MB --volume-totalsize=1GB
tenant access add succeeded

3. create a volume 'vol1' using short name

root@photon-eZ5ILvREQ [ ~ ]# docker volume create --driver=vmdk --name=vol1 -o size=100MB
vol1
root@photon-eZ5ILvREQ [ ~ ]# docker volume ls
DRIVER              VOLUME NAME
vmdk                vol1@datastore1

4. rename datastore from "datastore1" to "tmp-datastore1", verify that "vol1" is now in "tmp-datastore1"

[root@localhost:~] /usr/lib/vmware/vmdkops/bin/vmdkops_admin.py ls
Volume  Datastore       Created By VM  Created                   Attached To VM  Policy  Capacity  Used     Disk Format  Filesystem Type  Access      Attach As               
------  --------------  -------------  ------------------------  --------------  ------  --------  -------  -----------  ---------------  ----------  ----------------------  
vol1    tmp-datastore1  photon5        Mon Sep  5 01:47:03 2016  detached        N/A     100.00MB  13.00MB  thin         ext4             read-write  independent_persistent  

5. create another volume "vol2" with short name

root@photon-eZ5ILvREQ [ ~ ]# docker volume create --driver=vmdk --name=vol2 -o size=100MB
vol2
root@photon-eZ5ILvREQ [ ~ ]# docker volume ls
DRIVER              VOLUME NAME
vmdk                vol1@tmp-datastore1
vmdk                vol2@tmp-datastore1

[shuklanirdesh82]

I am still able to reproduce this issue on the latest plugin/driver.

root@photon-xVmYMbyTn [ ~ ]# rpm -qa | grep docker
docker-1.12.6-1.ph1.x86_64
docker-volume-vsphere-0.10.45bd720-1.x86_64

root@sc-rdops-vm07-dhcp-193-230:~] /usr/lib/vmware/vmdkops/bin/vmdkops_admin.py status
Version: 0.10.45bd720-0.0.1
Status: Running
Pid: 1202343
Port: 1019
LogConfigFile: /etc/vmware/vmdkops/log_config.json
LogFile: /var/log/vmware/vmdk_ops.log
LogLevel: INFO

Error message from docker host

root@photon-xVmYMbyTn [ ~ ]# docker volume create --driver=vmdk --name=MyVol1 -o size=1gb
Error response from daemon: create MyVol1: VolumeDriver.Create: Server returned an error: IndexError('list index out of range',)

[lipingxue]

Nirdesh and I talked. My test is slightly different with Nirdesh's test. He ran the test with only _DEFAULT tenant exist and we can reproduce it with the top of master. It looks like something related with _DEFAULT tenant handling.

[lipingxue]

I checked the log, and this is the root cause. For _DEFAULT tenant, when volume create using the short name (without @datastore), the datastore which VM lives will be used as default_datastore.
We use function "def get_datastore_name(config_path)" to get the datastore_name from config_path.

In this function, we call vmdk_utils.get_datastores() to get all datastores and check if any datastore name match the datastore name we get from config_path.

The logic in "vmdk_utils.get_datastores" has some issue since it will use the cached value instead of pulling the information again. This will have some issues when user change the datastore name.

[lipingxue]

I discussed with Mark offline. The fix I did in #959 is not the best one since it refresh datastore cache in each operation.
Based on our discussion, we decide there are two steps to fix #818
step1: force datastore cache to refresh for listVMDK. This fix is simple and also provide a workaround for the error hit in #818. When user see "IndexError('list index out of range',)" he/she need to run "docker volume ls" which will force datastore cache to refresh. After that, "docker volume create" will work.

step2: We checked the trace of this exception, and find that it caused by function "get_datastore_url" during the operation authorize call. After analyze the code, we found that function "get_datastore_url" is not needed during operation authorize call, and we can remove it by refactoring related code.

[lipingxue]

This issue has been fixed.