Workstation 7.1 "Failed to lock File"

D

dr_latino999

Limp Gawd
Joined
Jul 15, 2008
Messages
130
I'm having an issue in Workstation 7.1 where a VM that I suspended at 0530 would not come back to life at 0800 with the following error presented in the GUI -

Cannot Open the disk 'H:\Disk A\WHSVM.vmdk' or one of the snapshot disks it depends on. Reason, failed to lock file.

The log file is attached with the relevant section. I could not post the whole log as it exceeds the character limit for a post.

Host Operating System is Windows 7 Ultimate x64, and the guest OS is Windows Home Server . The guest OS has been running happily for about two years now and this is the first major problem it has exhibited. I have removed all *.lck files as mentioned in every single other instance of this problem with no avail. I have also reinstalled Workstation 7.1 as well, no dice. Mapping the drive seems to fail as well.

Any ideas would be greatly appreciated.

Code: 
Jun 21 21:39:07.204: vmx| CPU0: PMC: IA32, CORE 2 [c:0 f:1 e:1]
Jun 21 21:39:07.204: vmx| CPU1: PMC: IA32, CORE 2 [c:0 f:1 e:1]
Jun 21 21:39:07.204: vmx| CPU2: PMC: IA32, CORE 2 [c:0 f:1 e:1]
Jun 21 21:39:07.204: vmx| CPU3: PMC: IA32, CORE 2 [c:0 f:1 e:1]
Jun 21 21:39:07.217: vmx| Replay State = 0
Jun 21 21:39:07.217: vmx| minDEThreshold: 70
Jun 21 21:39:07.250: vmx| MMC: Initialized PLS=1 PLR=0 PFS=0 TS=1 BS=1 WZ=0 BufM=0 LOR=0 SOR=1 BlkP=32 W=50 PF=1100
Jun 21 21:39:07.250: vmx| MMCHK: Disabling checks which are not forced, cannot do checks on certain processors.
Jun 21 21:39:07.250: vmx| MStat: Creating Stat vm.uptime
Jun 21 21:39:07.250: vmx| MStat: Creating Stat vm.suspendTime
Jun 21 21:39:07.250: vmx| MStat: Creating Stat vm.powerOnTimeStamp
Jun 21 21:39:07.250: vmx| Setting thread 37 stack size to 1048576.
Jun 21 21:39:07.251: vmx| VMXAIOMGR: Using: simple=Generic unbuf=Compl
Jun 21 21:39:07.259: vmx| VMXVmdb_LoadRawConfig: Loading raw config
Jun 21 21:39:07.265: vmx| DISK: OPEN scsi0:0 'H:\Disk A\WHSVM.vmdk' persistent R[]
Jun 21 21:39:07.267: vmx| DISKLIB-DSCPTR: Opened [0]: "WHSVM-f001.vmdk" 0 (0xa)
Jun 21 21:39:07.267: vmx| DISKLIB-DSCPTR: Opened [1]: "WHSVM-f002.vmdk" 0 (0xa)
Jun 21 21:39:07.267: vmx| DISKLIB-DSCPTR: Opened [2]: "WHSVM-f003.vmdk" 0 (0xa)
Jun 21 21:39:07.267: vmx| DISKLIB-DSCPTR: Opened [3]: "WHSVM-f004.vmdk" 0 (0xa)
Jun 21 21:39:07.267: vmx| DISKLIB-DSCPTR: Opened [4]: "WHSVM-f005.vmdk" 0 (0xa)
Jun 21 21:39:07.268: vmx| DISKLIB-DSCPTR: Opened [5]: "WHSVM-f006.vmdk" 0 (0xa)
Jun 21 21:39:07.268: vmx| DISKLIB-DSCPTR: Opened [6]: "WHSVM-f007.vmdk" 0 (0xa)
Jun 21 21:39:07.268: vmx| DISKLIB-DSCPTR: Opened [7]: "WHSVM-f008.vmdk" 0 (0xa)
Jun 21 21:39:07.268: vmx| DISKLIB-DSCPTR: Opened [8]: "WHSVM-f009.vmdk" 0 (0xa)
Jun 21 21:39:07.268: vmx| DISKLIB-DSCPTR: Opened [9]: "WHSVM-f010.vmdk" 0 (0xa)
Jun 21 21:39:07.268: vmx| DISKLIB-DSCPTR: Opened [10]: "WHSVM-f011.vmdk" 0 (0xa)
Jun 21 21:39:07.268: vmx| DISKLIB-DSCPTR: Opened [11]: "WHSVM-f012.vmdk" 0 (0xa)
Jun 21 21:39:07.268: vmx| DISKLIB-DSCPTR: Opened [12]: "WHSVM-f013.vmdk" 0 (0xa)
Jun 21 21:39:07.268: vmx| DISKLIB-DSCPTR: Opened [13]: "WHSVM-f014.vmdk" 0 (0xa)
Jun 21 21:39:07.268: vmx| DISKLIB-DSCPTR: Opened [14]: "WHSVM-f015.vmdk" 0 (0xa)
Jun 21 21:39:07.269: vmx| DISKLIB-DSCPTR: Opened [15]: "WHSVM-f016.vmdk" 0 (0xa)
Jun 21 21:39:07.269: vmx| DISKLIB-DSCPTR: Opened [16]: "WHSVM-f017.vmdk" 0 (0xa)
Jun 21 21:39:07.269: vmx| DISKLIB-DSCPTR: Opened [17]: "WHSVM-f018.vmdk" 0 (0xa)
Jun 21 21:39:07.269: vmx| DISKLIB-DSCPTR: Opened [18]: "WHSVM-f019.vmdk" 0 (0xa)
Jun 21 21:39:07.269: vmx| DISKLIB-DSCPTR: Opened [19]: "WHSVM-f020.vmdk" 0 (0xa)
Jun 21 21:39:07.269: vmx| DISKLIB-DSCPTR: Opened [20]: "WHSVM-f021.vmdk" 0 (0xa)
Jun 21 21:39:07.269: vmx| DISKLIB-DSCPTR: Opened [21]: "WHSVM-f022.vmdk" 0 (0xa)
Jun 21 21:39:07.269: vmx| DISKLIB-DSCPTR: Opened [22]: "WHSVM-f023.vmdk" 0 (0xa)
Jun 21 21:39:07.269: vmx| DISKLIB-DSCPTR: Opened [23]: "WHSVM-f024.vmdk" 0 (0xa)
Jun 21 21:39:07.269: vmx| DISKLIB-DSCPTR: Opened [24]: "WHSVM-f025.vmdk" 0 (0xa)
Jun 21 21:39:07.269: vmx| DISKLIB-DSCPTR: Opened [25]: "WHSVM-f026.vmdk" 0 (0xa)
Jun 21 21:39:07.270: vmx| DISKLIB-DSCPTR: Opened [26]: "WHSVM-f027.vmdk" 0 (0xa)
Jun 21 21:39:07.270: vmx| DISKLIB-DSCPTR: Opened [27]: "WHSVM-f028.vmdk" 0 (0xa)
Jun 21 21:39:07.270: vmx| DISKLIB-DSCPTR: Opened [28]: "WHSVM-f029.vmdk" 0 (0xa)
Jun 21 21:39:07.270: vmx| DISKLIB-DSCPTR: Opened [29]: "WHSVM-f030.vmdk" 0 (0xa)
Jun 21 21:39:07.270: vmx| DISKLIB-DSCPTR: Opened [30]: "WHSVM-f031.vmdk" 0 (0xa)
Jun 21 21:39:07.270: vmx| DISKLIB-DSCPTR: Opened [31]: "WHSVM-f032.vmdk" 0 (0xa)
Jun 21 21:39:07.270: vmx| DISKLIB-DSCPTR: Opened [32]: "WHSVM-f033.vmdk" 0 (0xa)
Jun 21 21:39:07.270: vmx| DISKLIB-DSCPTR: Opened [33]: "WHSVM-f034.vmdk" 0 (0xa)
Jun 21 21:39:07.270: vmx| DISKLIB-DSCPTR: Opened [34]: "WHSVM-f035.vmdk" 0 (0xa)
Jun 21 21:39:07.270: vmx| DISKLIB-DSCPTR: Opened [35]: "WHSVM-f036.vmdk" 0 (0xa)
Jun 21 21:39:07.271: vmx| DISKLIB-DSCPTR: Opened [36]: "WHSVM-f037.vmdk" 0 (0xa)
Jun 21 21:39:07.271: vmx| DISKLIB-DSCPTR: Opened [37]: "WHSVM-f038.vmdk" 0 (0xa)
Jun 21 21:39:07.271: vmx| DISKLIB-DSCPTR: Opened [38]: "WHSVM-f039.vmdk" 0 (0xa)
Jun 21 21:39:07.271: vmx| DISKLIB-DSCPTR: Opened [39]: "WHSVM-f040.vmdk" 0 (0xa)
Jun 21 21:39:07.271: vmx| DISKLIB-DSCPTR: Opened [40]: "WHSVM-f041.vmdk" 0 (0xa)
Jun 21 21:39:07.271: vmx| DISKLIB-DSCPTR: Opened [41]: "WHSVM-f042.vmdk" 0 (0xa)
Jun 21 21:39:07.271: vmx| DISKLIB-DSCPTR: Opened [42]: "WHSVM-f043.vmdk" 0 (0xa)
Jun 21 21:39:07.271: vmx| DISKLIB-DSCPTR: Opened [43]: "WHSVM-f044.vmdk" 0 (0xa)
Jun 21 21:39:07.271: vmx| DISKLIB-DSCPTR: Opened [44]: "WHSVM-f045.vmdk" 0 (0xa)
Jun 21 21:39:07.271: vmx| DISKLIB-DSCPTR: Opened [45]: "WHSVM-f046.vmdk" 0 (0xa)
Jun 21 21:39:07.272: vmx| DISKLIB-DSCPTR: Opened [46]: "WHSVM-f047.vmdk" 0 (0xa)
Jun 21 21:39:07.272: vmx| DISKLIB-LINK  : Opened 'H:\Disk A\WHSVM.vmdk' (0xa): twoGbMaxExtentFlat, 188743680 sectors / 90 GB.
Jun 21 21:39:07.272: vmx| DISKLIB-LIB   : Opened "H:\Disk A\WHSVM.vmdk" (flags 0xa).
Jun 21 21:39:07.272: vmx| DiskGetGeometry: Reading of disk partition table
Jun 21 21:39:07.282: vmx| DISK: OPEN 'H:\Disk A\WHSVM.vmdk' Geo (13217/255/56) BIOS Geo (11748/255/63)
Jun 21 21:39:07.319: vmx| DISK: OPEN scsi0:1 'G:\Disk B\disk-b.vmdk' independent-persistent R[]
Jun 21 21:39:07.321: vmx| DISKLIB-DSCPTR: Opened [0]: "disk-b-f001.vmdk" 0 (0xa)
Jun 21 21:39:07.321: vmx| DISKLIB-LINK  : Opened 'G:\Disk B\disk-b.vmdk' (0xa): twoGbMaxExtentFlat, 2927624192 sectors / 1.4 TB.
Jun 21 21:39:07.321: vmx| DISKLIB-LIB   : Opened "G:\Disk B\disk-b.vmdk" (flags 0xa).
Jun 21 21:39:07.321: vmx| DiskGetGeometry: Reading of disk partition table
Jun 21 21:39:07.322: vmx| DISK: OPEN 'G:\Disk B\disk-b.vmdk' Geo (205015/255/56) BIOS Geo (182236/255/63)
Jun 21 21:39:07.375: vmx| DISK: OPEN scsi0:2 'H:\Disk A\WHSVM.vmdk' independent-persistent R[]
Jun 21 21:39:09.992: vmx| FILE: WaitForPossession timeout on 'H:\Disk A\WHSVM.vmdk.lck\M06211.lck' due to a local process (3620)
Jun 21 21:39:09.993: vmx| FILE: FileIO_Lock on 'H:\Disk A\WHSVM.vmdk' failed: Lock timed out
Jun 21 21:39:09.993: vmx| DISKLIB-DSCPTR: DescriptorOpenWithRetry: Descriptor file 'H:\Disk A\WHSVM.vmdk' locked (try 0)
Jun 21 21:39:13.608: vmx| FILE: WaitForPossession timeout on 'H:\Disk A\WHSVM.vmdk.lck\M06211.lck' due to a local process (3620)
Jun 21 21:39:13.609: vmx| FILE: FileIO_Lock on 'H:\Disk A\WHSVM.vmdk' failed: Lock timed out
Jun 21 21:39:13.609: vmx| DISKLIB-DSCPTR: DescriptorOpenWithRetry: Descriptor file 'H:\Disk A\WHSVM.vmdk' locked (try 1)
Jun 21 21:39:17.224: vmx| FILE: WaitForPossession timeout on 'H:\Disk A\WHSVM.vmdk.lck\M06211.lck' due to a local process (3620)
Jun 21 21:39:17.224: vmx| FILE: FileIO_Lock on 'H:\Disk A\WHSVM.vmdk' failed: Lock timed out
Jun 21 21:39:17.224: vmx| DISKLIB-DSCPTR: DescriptorOpenWithRetry: Descriptor file 'H:\Disk A\WHSVM.vmdk' locked (try 2)
Jun 21 21:39:20.839: vmx| FILE: WaitForPossession timeout on 'H:\Disk A\WHSVM.vmdk.lck\M06211.lck' due to a local process (3620)
Jun 21 21:39:20.839: vmx| FILE: FileIO_Lock on 'H:\Disk A\WHSVM.vmdk' failed: Lock timed out
Jun 21 21:39:20.839: vmx| DISKLIB-DSCPTR: DescriptorOpenWithRetry: Descriptor file 'H:\Disk A\WHSVM.vmdk' locked (try 3)
Jun 21 21:39:24.455: vmx| FILE: WaitForPossession timeout on 'H:\Disk A\WHSVM.vmdk.lck\M06211.lck' due to a local process (3620)
Jun 21 21:39:24.455: vmx| FILE: FileIO_Lock on 'H:\Disk A\WHSVM.vmdk' failed: Lock timed out
Jun 21 21:39:24.455: vmx| DISKLIB-DSCPTR: DescriptorOpenWithRetry: Descriptor file 'H:\Disk A\WHSVM.vmdk' locked (try 4)
Jun 21 21:39:25.455: vmx| DISKLIB-DSCPTR: DescriptorDetermineType: failed to open 'H:\Disk A\WHSVM.vmdk': Failed to lock the file (43)
Jun 21 21:39:25.455: vmx| DISKLIB-LINK  : "H:\Disk A\WHSVM.vmdk" : failed to open (Failed to lock the file).  
Jun 21 21:39:25.455: vmx| DISKLIB-CHAIN : "H:\Disk A\WHSVM.vmdk" : failed to open (Failed to lock the file).
Jun 21 21:39:25.455: vmx| DISKLIB-LIB   : Failed to open 'H:\Disk A\WHSVM.vmdk' with flags 0xa (Failed to lock the file).
Jun 21 21:39:25.455: vmx| DISK: Cannot open disk "H:\Disk A\WHSVM.vmdk": Failed to lock the file (16392).
Jun 21 21:39:25.455: vmx| Msg_Post: Error
Jun 21 21:39:25.455: vmx| [msg.disk.noBackEnd] Cannot open the disk 'H:\Disk A\WHSVM.vmdk' or one of the snapshot disks it depends on.
Jun 21 21:39:25.455: vmx| [msg.disk.configureDiskError] Reason: Failed to lock the file.----------------------------------------
 
from what i see looks like Local Process 3620 is either locking the file or its the program trying to lock the file, either way i would look @ your PID for a 3620 and see what it is. i could easily tell u the command for esx to find out what the mac address is using the file but sadly i dont know it for workstation..
 
Local process at the time for 3620 was an instance of vmware-vmx.exe, that is created wen I attempt to un-suspend the machine.
 
well i know in esx if u edit the vmx file it should have information about the suspended vm like memory suspend file state information that u could possibly remove.

if u wanna avoid that try also just creating a new vm and try attaching the hard drive to that newly created vm (build it with same specs as other) if the hard drive is still locked by a process u will know...
 
If you can show me where to remove the line referencing the suspended state in the .VMX file that would be great. Since the machine is currently suspended, I can't modify any of the settings it seems.

Code: 
.encoding = "windows-1252"
config.version = "8"
virtualHW.version = "7"
numvcpus = "2"
maxvcpus = "4"
scsi0.present = "TRUE"
scsi0.virtualDev = "lsisas1068"
memsize = "1100"
ethernet0.present = "TRUE"
ethernet0.virtualDev = "e1000"
ethernet0.wakeOnPcktRcv = "FALSE"
ethernet0.addressType = "generated"
usb.present = "TRUE"
ehci.present = "TRUE"
pciBridge0.present = "TRUE"
pciBridge4.present = "TRUE"
pciBridge4.virtualDev = "pcieRootPort"
pciBridge4.functions = "8"
pciBridge5.present = "TRUE"
pciBridge5.virtualDev = "pcieRootPort"
pciBridge5.functions = "8"
pciBridge6.present = "TRUE"
pciBridge6.virtualDev = "pcieRootPort"
pciBridge6.functions = "8"
pciBridge7.present = "TRUE"
pciBridge7.virtualDev = "pcieRootPort"
pciBridge7.functions = "8"
vmci0.present = "TRUE"
roamingVM.exitBehavior = "go"
displayName = "WHSVM"
guestOS = "winnetbusiness"
nvram = "WHSVM.nvram"
virtualHW.productCompatibility = "hosted"
extendedConfigFile = "WHSVM.vmxf"
checkpoint.vmState = "WHSVM.vmss"
ethernet0.generatedAddress = "00:0c:29:bd:4c:3d"
ethernet0.linkStatePropagation.enable = "FALSE"
tools.syncTime = "TRUE"
uuid.location = "56 4d 6b d2 a3 14 15 29-80 c4 e1 01 e2 df 8b a7"
uuid.bios = "56 4d 75 d2 b8 4b 8b c2-3e 90 f1 0b b0 bd 4c 3d"
cleanShutdown = "FALSE"
replay.supported = "FALSE"
unity.wasCapable = "FALSE"
debugStub.winOffsets.version = "7"
replay.filename = ""
pciBridge0.pciSlotNumber = "17"
pciBridge4.pciSlotNumber = "21"
pciBridge5.pciSlotNumber = "22"
pciBridge6.pciSlotNumber = "23"
pciBridge7.pciSlotNumber = "24"
scsi0.pciSlotNumber = "160"
usb.pciSlotNumber = "32"
ethernet0.pciSlotNumber = "33"
ehci.pciSlotNumber = "35"
vmci0.pciSlotNumber = "36"
scsi0.sasWWID = "50 05 05 62 b8 4b 8b c0"
vmotion.checkpointFBSize = "134217728"
usb:0.present = "TRUE"
usb:1.present = "TRUE"
ethernet0.generatedAddressOffset = "0"
vmci0.id = "-1329771459"
tools.remindInstall = "FALSE"
usb:1.deviceType = "hub"
usb:0.deviceType = "mouse"
debugStub.winOffsets.value = "0x98,0x94,0x18,0x180,0x164,16,400,0x224,0x220,0x1e8,0x21c,0x74,0x18,0x18,0x20,0x24,4,0x258,0x0,0xc,0x14,0x200000,0x1a0,0xc,0xc,0x18,0x128,0x1e4"
scsi0:1.present = "TRUE"
scsi0:1.fileName = "disk-b.vmdk"
scsi0:1.redo = ""
gui.exitOnCLIHLT = "TRUE"
scsi0:2.present = "TRUE"
scsi0:2.fileName = "WHSVM.vmdk"
scsi0:2.mode = "independent-persistent"
scsi0:2.redo = ""
scsi0:1.mode = "independent-persistent"
mks.enable3d = "TRUE"
scsi0:4.present = "TRUE"
scsi0:4.fileName = "disk-d.vmdk"
scsi0:4.mode = "independent-persistent"
scsi0:4.redo = ""
ethernet0.vnet = "VMnet0"
ethernet0.connectionType = "custom"
fileSearchPath = "E:\Disk A;F:\Disk D;D:\Disk-F;I:\Disk C;G:\Disk B;H:\Disk A;D:\Disk A;."
scsi0:0.present = "TRUE"
scsi0:0.fileName = "H:\Disk A\WHSVM.vmdk"
ide0:0.present = "TRUE"
scsi0:0.redo = ""
ide0:0.autodetect = "TRUE"
ide0:0.deviceType = "cdrom-raw"
scsi0:3.present = "TRUE"
ide0:0.startConnected = "FALSE"
usb.autoConnect.device0 = ""
ide0:0.fileName = "auto detect"
scsi0:3.fileName = "disk-f.vmdk"
scsi0:3.mode = "independent-persistent"
scsi0:3.redo = ""
isolation.tools.vmdebug.disable = "TRUE"
debugStub.allow = "FALSE"
tools.upgrade.policy = "upgradeAtPowerCycle"
scsi0:6.present = "FALSE"
scsi0:8.present = "FALSE"
scsi0:5.present = "FALSE"
ide0:1.present = "FALSE"
sound.present = "FALSE"
ide1:0.present = "FALSE"
floppy0.present = "FALSE"

I am actually going to build a copy of Vail later today to see if it can accept the drive, and if it does it gives me a good reason to move from WHS-1 --> 2.
 
Added information, the .vmdk in question was successfully opened in another VM. I then removed it from the second VM, tried to initialize it again with the first VM and the reported initial error occurred again. This leads me to believe the disk isn't hosed but an issue with the configuration files of the vm; correct assumption?
 
backup your vmx

then remove
checkpoint.vmState = "WHSVM.vmss"

and u can change this to TRUE, should make it so it thinks it was shutdown cleanly since you have booted it in another vmx.
cleanShutdown = "FALSE"

other alternative is just ot use new vmx that u used and it should work fine... if the system fired as expected then the vmdk shouldnt be hosed..
 
Removed checkpoint, changed clean, and no dice; same error. I may just try a clean vmx tomorrow for WHS, but if I can get Vail functioning then its plan B.
 
You must log in or register to reply here.
Back
Top