Power on operation of a Virtual Machine in a vvol datastore fails with "5 (Input/output error)"

Products

• VMware vSphere ESXi
• VMware vSphere ESX 8.x
• VMware vSphere ESX 7.x

Issue/Introduction

Unable to power on a Virtual Machine from a vvol datastore after changing the storage policy or any storage related reconfigure operation. 

 

We see the below errors in the logs

YYYY-MM-DDTHH:MM:SS.552Z info hostd[2106829] [Originator@6876 sub=DiskLib opID=m2u3vzjr-624327-auto-ddqg-h5:70053160-61-01-cb-4221 user=vpxuser:testuser] DISKLIB-CHAIN : "/vmfs/volumes/vvol:2bb23a3e1d3f4642-957b580d1e780f9e/naa.################/testvm_3.vmdk" : fail(Input/output error).
YYYY-MM-DDTHH:MM:SS.552Z info hostd[2106829] [Originator@6876 sub=DiskLib opID=m2u3vzjr-624327-auto-ddqg-h5:70053160-61-01-cb-4221 user=vpxuser:testuser] DISKLIB-LIB : Failed to open '/vmfs/volumes/vvol:2bb23a3e1d3f4642-957b580d1e780f9e/naa.################/testvm flags 0xa Input/output error (327689).

YYYY-MM-DDTHH:MM:SS.552Z info hostd[2106829] [Originator@6876 sub=DiskLib opID=m2u3vzjr-624327-auto-ddqg-h5:70053160-61-01-cb-4221 user=vpxuser:testuser] DISKLIB-LIB_MISC : DiskLibChangePolicyWithOpen: Unable to open disk '/vmfs/volumes/vvol:2bb23a3e1d3f4642-957b580d1e780f9e/naa.################/testvm_3.vmdk' : Input/output error (327689).

YYYY-MM-DDTHH:MM:SS.552Z verbose hostd[2106829] [Originator@6876 sub=Vigor.Vmsvc.vm:/vmfs/volumes/vvol:2bb23a3e1d3f4642-957b580d1e780f9e/naa.################/testvm.vmx opID=m2u3vzjr-624327-auto-ddqg-h5:70053160-61-01-cb-4221 user=vpxuser:testuser] Set disk policy storage policy change failure: Input/output error.

This issue does not affect all the Virtual machines from the vvol datastore. 

Virtual Machines running from the same vvol datastore can be powered on successfully. 

After removing the vmdks with the input/output error from the virtual machine, the power on operation is successful.

This issue typically affects virtual machines with large vmdk sizes. 

Cause

This issue occurs when the storage array takes longer time to complete the requested operation. 

The array marks the volume in a transient state . When a volume is marked by the array to be in transition, it will not allow the ESXi host to open the volume we can observe  "bindVirtualVolume" failure messages. 

 

YYYY-MM-DDTHH:MM:SS.991-0800 error vvold[2100087] [⋮ sub=Default opID=m2u3vzjr-554500-auto-bvuu-h5:70038029-26-01-d0-7db1] VasaOp::IsSuccessful [#1057448]: updateStorageProfileForVirtualVolume transient failure: 14 (RESOURCE_BUSY / Resource in use : vVol with WWN 60002AC0000000000701CEEF000XXXX is in transition / )
YYYY-MM-DDTHH:MM:SS.991-0800 warning vvold[2100087] [⋮ sub=Default opID=m2u3vzjr-554500-auto-bvuu-h5:70038029-26-01-d0-7db1] VasaOp[#1057448] ===> Transient failure updateStorageProfileForVirtualVolume VP (storage_policy_name) retry=false, batchOp=false container=2bb23a3e-1d3f-4642-957b-580d1e780f9e timeElapsed=220 msecs (#outstanding 0)
YYYY-MM-DDTHH:MM:SS.991-0800 error vvold[2100087] [⋮ sub=Default opID=m2u3vzjr-554500-auto-bvuu-h5:70038029-26-01-d0-7db1] VasaOp[#1057448] ===> FINAL FAILURE updateStorageProfileForVirtualVolume, error (RESOURCE_BUSY / Resource in use : vVol with WWN 60002AC0000000000701CEEF0002XXXX is in transition / ) VP (storage_policy_name) Container (2bb23a3e-1d3f-4642-957b-580d1e780f9e) timeElapsed=220 msecs (#outstanding 0)

The above logs clearly prints the message received from storage array which indicates the volume is in "transition". 

 

YYYY-MM-DDTHH:MM:SS.255-0800 info vvold[11523010] [⋮ sub=Default opID=m2u3vzjr-554500-auto-bvuu-h5:70038029-26-01-d0-7db1] Came to SI::BindVirtualVolume: esxContainerId 2bb23a3e1d3f4642-957b580d1e780f9e VVol Id naa.################################ bindType Normal (isConfigVvol: false)
YYYY-MM-DDTHH:MM:SS.255-0800 info vvold[11523010] [⋮ sub=Default opID=m2u3vzjr-554500-auto-bvuu-h5:70038029-26-01-d0-7db1] VasaOp::BindVirtualVolume [#1057450]: ===> Issuing 'bindVirtualVolume' to VP [volumename:Connected (Outstanding 0/4)]
YYYY-MM-DDTHH:MM:SS.270-0800 error vvold[11523010] [⋮ sub=Default opID=m2u3vzjr-554500-auto-bvuu-h5:70038029-26-01-d0-7db1] VasaOp::IsSuccessful [#1057450]: bindVirtualVolume transient failure: 22 (STORAGE_FAULT / ADB conversion error. Details: Invalid type for anyType / )
YYYY-MM-DDTHH:MM:SS.270-0800 warning vvold[11523010] [⋮ sub=Default opID=m2u3vzjr-554500-auto-bvuu-h5:70038029-26-01-d0-7db1] VasaOp[#1057450] ===> Transient failure bindVirtualVolume VP (volume name) retry=false, batchOp=false container=2bb23a3e-1d3f-4642-957b-580d1e780f9e timeElapsed=15 msecs (#outstanding 0)
YYYY-MM-DDTHH:MM:SS.270-0800 error vvold[11523010] [⋮ sub=Default opID=m2u3vzjr-554500-auto-bvuu-h5:70038029-26-01-d0-7db1] VasaOp[#1057450] ===> FINAL FAILURE bindVirtualVolume, error (STORAGE_FAULT / ADB conversion error. Details: Invalid type for anyType / ) VP (volume name) Container (2bb23a3e-1d3f-4642-957b-580d1e780f9e) timeElapsed=15 msecs (#outstanding 0)

 

The above log indicates the failure of the bindVirtualVolume API, which is used by ESXi to open a vVol object, this again was failed by array.

Resolution

This could be a transient condition and once the operation is completed on the array, the virtual machine can be powered on.

But if the volume continues to be in transition state, then please engage the array vendor to recover the volume. 

Additional Information

In this case, the issue occured after the user unregistered the virtual machine and re-registered it. In a vvol datatsore the storage policy is tagged to the vmoref identifier. So, once the Virtual Machine is un-registered the vvol storage policy changes to default.