Volume create fails with meta-data in use error

[msterin]

Made handing of missing metafile less harsh.

If the metadata file is missing (which could happen when some ops fail and disk created OK,
but metadata file is not created - I had it a few times in test though I am not sure which op exactly failed) the whole plugin goes into unstable state due to unhandled exception (below).

Backtrace (from my private branch, so line numbers could be a bit off)

10/15/16 06:12:28 41380 [photon-1] [INFO   ] executeRequest 'list' completed with ret=[{u'Attributes': {}, u'Name': 'myvol'}, {u'Attributes': {}, u'Name': 'refCountTestVol'}]
10/15/16 06:12:33 41380 [photon-1] [ERROR  ] Failed to access /vmfs/volumes/datastore1/dockvols/refCountTestVol-8bfdeb99e642a231.vmfd
Traceback (most recent call last):
  File "/usr/lib/vmware/vmdkops/Python/kvESX.py", line 242, in load
    with open(meta_file, "r") as fh:
IOError: [Errno 2] No such file or directory: '/vmfs/volumes/datastore1/dockvols/refCountTestVol-8bfdeb99e642a231.vmfd'
10/15/16 06:12:33 41380 [photon-1] [ERROR  ] 'NoneType' object has no attribute '__getitem__'
Traceback (most recent call last):
  File "/usr/lib/vmware/vmdkops/bin/vmdk_ops.py", line 1186, in main
    handleVmciRequests(port)
  File "/usr/lib/vmware/vmdkops/bin/vmdk_ops.py", line 1143, in handleVmciRequests
    opts=opts)
  File "/usr/lib/vmware/vmdkops/bin/vmdk_ops.py", line 568, in executeRequest
    response = getVMDK(vmdk_path, vol_name, datastore)
  File "/usr/lib/vmware/vmdkops/bin/vmdk_ops.py", line 400, in getVMDK
    return vol_info(kv.getAll(vmdk_path), kv.get_vol_info(vmdk_path), datastore)
  File "/usr/lib/vmware/vmdkops/bin/vmdk_ops.py", line 350, in vol_info
    vinfo = {CREATED_BY_VM : vol_meta[kv.CREATED_BY],
TypeError: 'NoneType' object has no attribute '__getitem__'

@pdhamdhere - please adjust priority as needed

Assigning to @govint per git blame for return vol_info(kv.getAll(vmdk_path), kv.get_vol_info(vmdk_path), datastore)

[govint]

@brunotm Can you say what version of ESX you are using for the test that failed.
Whats happened is just after the KV file got created (its created by ESX) on vsan, the file is opened to write the initial KV data. Apparently the system still has the file open and hence the write fails - with a busy error. I'll need to check this behavior on vsan more as volp00 creation went thru ok at around the same time (almost in parallel).

---

Failed to save meta-data for /vmfs/volumes/vsanDatastore/dockvols/volP10.vmdk
IOError: [Errno 16] Device or resource busy: '/vmfs/volumes/vsanDatastore/dockvols/volP10-77ad58548f419806.vmfd'

---

While in parallel volp00 created fine.

@brunotm - Were any parallel commands being run when the create test was happening? If by chance the disk was opened in parallel the KV file may not be usable.

[brunotm]

@govint
Version 6u2.

Also I don't record seeing this error on non-vsan data stores.
On Mon, 17 Oct 2016 at 19:39, Thiruvengada Govindan <
notifications@github.com> wrote:

@brunotm https://github.com/brunotm Can you say what version of ESX you
are using for the test that failed.
Whats happened is just after the KV file got created (its created by ESX)
on vsan, the file is opened to write the initial KV data. Apparently the
system still has the file open and hence the write fails - with a busy
error. I'll need to check this behavior on vsan more as volp00 creation
went thru ok at around the same time (almost in parallel).

Failed to save meta-data for
/vmfs/volumes/vsanDatastore/dockvols/volP10.vmdk
IOError: [Errno 16] Device or resource busy:
'/vmfs/volumes/vsanDatastore/dockvols/volP10-77ad58548f419806.vmfd'

While in parallel volp00 created fine.

—
You are receiving this because you were mentioned.

Reply to this email directly, view it on GitHub
#626 (comment),
or mute the thread
https://github.com/notifications/unsubscribe-auth/AGCQDkji9JGXyZ3ZdvBRcYwT1wV0Cynuks5q08DPgaJpZM4KYo5y
.

Bruno Moura
+351 932 518 676

[govint]

Renamed the issue as we have a couple of cases which are not reproducible. This issue is for what Bruno reported where a volume create failed with the KV file being in use during creation.

@brunotm can you say what test was run when this error was seen, can you post the steps used.

[brunotm]

@govint

Occasionally observed this issue with the code from #612 when running make test-vm in a vsan (only?) environment.

ESX 6u2 with a vsan datastore
Docker host VMs Ubuntu 16.04
docker version 1.12.1

Logs http://pastebin.com/UybXCQME

[govint]

Been trying this with VMFS and without the threaded code. I'll need to check this with the threading code included. Seems like the KV file is being accessed ahead of it being written. Will wait for the threading code to be submitted in its final form.

[brunotm]

@govint

Been trying this with VMFS and without the threaded code. I'll need to check this with the threading code included. Seems like the KV file is being accessed ahead of it being written. Will wait for the threading code to be submitted in its final form.

I think his unlikely for the file busy issue in kv.save() when creating a volume. looks more like a timing issue for the esx to release the file lock between kv.create() and kv.save().

If you can, would be nice to know the description of the error codes returned by the disklib, mainly 4008 and 27 (this one is from memory).

Thanks!

[govint]

Closing with the changes merged via #708. All analysis is on #695