The original message was a reload attempt for vcl-n-004. The "MAC addresses do not match" line is expected since it was looking at vcl-n-001's vmx file.
The vcld.log output in the 2nd message was a reload attempt for vcl-n-001. The code found an existing vmx file for this VM: vcl-n-001_27. It checked if this vmx file was registered and determined it was not. Because of this, it didn't attempt to unregister a VM and went straight to attempting to delete the directory. For some reason, this failed. Everything in the log output you provided looks to be working as intended from the VCL perspective. More information is necessary to determine what cause the deletion to fail. The full output from vcld.log would be helpful. Is the vcl_workspace datastore shared by multiple hosts? This error would occur if the VM was loaded on another host using the same datastore. If the datastore isn't shared, there may have been a problem on the host. Check /var/log/vmware/hostd.log and search for "CannotDeleteFile". If the problem occurred before VMware archived hostd.log, you may have to look in one of the hostd-xxxx.log.gz file which corresponds to the date the error occurred. If you find the corresponding CannotDeleteFile fault in hostd.log, there may be more details. -Andy On Thu, Apr 3, 2014 at 11:08 AM, Mike Haudenschild <[email protected]> wrote: > Hi David, > > I'm fixated on this line in the log: > > 2014-04-02 > 11:07:09|22252|91:91|reload|VMware.pm:get_active_vmx_file_path(1026)|ignoring > vcl-n-001_27-v8.vmx because MAC addresses do not match the ones being used > by vcl-n-004 > > The fact you can reload a VM means that VCL is talking to VMWare, but if the > MAC address isn't what VCL expects it might be assuming that's not the VM > it's looking for when it's searching for / confirming it found the correct > VM to shut down. If VCL cannot shut down the VM, it probably wouldn't be > able to delete the .vmx file because it would still be in use by the > hypervisor. > > Regards, > Mike > > > On Thu, Apr 3, 2014 at 10:36 AM, David DeMizio <[email protected]> wrote: >> >> Hello, >> >> any other ideas on what might be causing this. I can post more logs if >> needed. Thank You >> >> >> >> >> >> On Wed, Apr 2, 2014 at 1:28 PM, David DeMizio <[email protected]> wrote: >>> >>> I took the following steps: >>> >>> 1) I powered off the vm manually( so VCL must not be able to power off >>> the vm) >>> 2) I reloaded the machine and it was successful, VCL was now able to >>> delete the file because vm was powered off >>> >>> however, it left the old vm in the inventory so I had to manually remove >>> from inventory using the vsphere client. >>> >>> >>> >>> >>> >>> On Wed, Apr 2, 2014 at 12:47 PM, Dmitri Chebotarov <[email protected]> >>> wrote: >>>> >>>> Hi David >>>> >>>> Is the problem with VCL not able to shutdown running VM? Or it cannot >>>> delete file/folder? >>>> >>>> If VM is off, can you try to delete file/folder manually from vSphere >>>> client? >>>> >>>> -- >>>> Thank you, >>>> >>>> Dmitri Chebotarov >>>> VCL Sys Eng, Engineering & Architectural Support, TSD - Ent Servers & >>>> Messaging >>>> 223 Aquia Building, Ffx, MSN: 1B5 >>>> Phone: (703) 993-6175 | Fax: (703) 993-3404 >>>> >>>> >>>> On Apr 2, 2014, at 11:54 , David DeMizio <[email protected]> wrote: >>>> >>>> > They all appear to be mounted and I can browse the datastore from >>>> > vcenter. path looks good.. >>>> > >>>> > >>>> > David DeMizio >>>> > Academic Systems Coordinator >>>> > Office of Information Technology >>>> > New College of Florida >>>> > Phone: 941-487-4222 | Fax: 941-487-4356 >>>> > www.ncf.edu >>>> > >>>> > >>>> > On Wed, Apr 2, 2014 at 11:43 AM, António Aragão <[email protected]> >>>> > wrote: >>>> > Inspect that all your repositories are well mounted. See if the paths >>>> > are ok. >>>> > >>>> > 2014-04-02 16:39 GMT+01:00 David DeMizio <[email protected]>: >>>> > > I have added some more logs. basically it can't delete the vm files. >>>> > > >>>> > > 2014-04-02 >>>> > > 11:20:34|23809|94:94|reload|VMware.pm:is_vm_registered(4427)|VM >>>> > > is not registered: >>>> > > '/vmfs/volumes/vcl_workspace/vcl-n-001_27-v8/vcl-n-001_27-v8.vmx' >>>> > > 2014-04-02 >>>> > > 11:20:34|23809|94:94|reload|VMware.pm:get_vmx_info(5313)|attempting >>>> > > to >>>> > > retrieve info from vmx file: >>>> > > /vmfs/volumes/vcl_workspace/vcl-n-001_27-v8/vcl-n-001_27-v8.vmx >>>> > > 2014-04-02 >>>> > > >>>> > > 11:20:34|23809|94:94|reload|Module.pm:code_loop_timeout(887)|attempting >>>> > > to >>>> > > copy file from VM host to management node: >>>> > > nc-vcenter:'[vcl_workspace] >>>> > > vcl-n-001_27-v8/vcl-n-001_27-v8.vmx' --> >>>> > > '/tmp/C387xsQmYu/vcl-n-001_27-v8.vmx', maximum of 50 seconds >>>> > > 2014-04-02 >>>> > > 11:20:34|23809|94:94|reload|vSphere_SDK.pm:__ANON__(1812)|copied >>>> > > file from VM host to management node: >>>> > > nc-vcenter.network.ncf.edu:'[vcl_workspace] >>>> > > vcl-n-001_27-v8/vcl-n-001_27-v8.vmx' --> >>>> > > '/tmp/C387xsQmYu/vcl-n-001_27-v8.vmx' >>>> > > 2014-04-02 >>>> > > >>>> > > 11:20:34|23809|94:94|reload|Module.pm:code_loop_timeout(900)|attempting >>>> > > to >>>> > > copy file from VM host to management node: >>>> > > nc-vcenter:'[vcl_workspace] >>>> > > vcl-n-001_27-v8/vcl-n-001_27-v8.vmx' --> >>>> > > '/tmp/C387xsQmYu/vcl-n-001_27-v8.vmx', code returned true >>>> > > 2014-04-02 >>>> > > >>>> > > 11:20:34|23809|94:94|reload|vSphere_SDK.pm:get_file_contents(1874)|retrieved >>>> > > 99 lines from file: '/tmp/C387xsQmYu/vcl-n-001_27-v8.vmx' >>>> > > 2014-04-02 >>>> > > 11:20:34|23809|94:94|reload|VMware.pm:get_vmx_info(5399)|vmdk >>>> > > path appears to be relative: >>>> > > vmwarewin7-SocialScience27-v8-000001.vmdk, >>>> > > prepending the vmx directory: >>>> > > >>>> > > /vmfs/volumes/vcl_workspace/vcl-n-001_27-v8/vmwarewin7-SocialScience27-v8-000001.vmdk >>>> > > 2014-04-02 >>>> > > 11:20:34|23809|94:94|reload|VMware.pm:delete_vm(5580)|attempting >>>> > > to delete vmx directory: /vmfs/volumes/vcl_workspace/vcl-n-001_27-v8 >>>> > > 2014-04-02 >>>> > > >>>> > > 11:20:34|23809|94:94|reload|vSphere_SDK.pm:delete_file(1596)|attempting >>>> > > to >>>> > > delete file: [vcl_workspace] vcl-n-001_27-v8 >>>> > > 2014-04-02 11:20:35|23413|vcld:main(167)|lastcheckin time updated >>>> > > for >>>> > > management node 1: 2014-04-02 11:20:35 >>>> > > 2014-04-02 11:20:40|23413|vcld:main(167)|lastcheckin time updated >>>> > > for >>>> > > management node 1: 2014-04-02 11:20:40 >>>> > > 2014-04-02 11:20:45|23413|vcld:main(167)|lastcheckin time updated >>>> > > for >>>> > > management node 1: 2014-04-02 11:20:45 >>>> > > 2014-04-02 11:20:50|23413|vcld:main(167)|lastcheckin time updated >>>> > > for >>>> > > management node 1: 2014-04-02 11:20:50 >>>> > > 2014-04-02 11:20:55|23413|vcld:main(167)|lastcheckin time updated >>>> > > for >>>> > > management node 1: 2014-04-02 11:20:55 >>>> > > 2014-04-02 11:21:00|23413|vcld:main(167)|lastcheckin time updated >>>> > > for >>>> > > management node 1: 2014-04-02 11:21:00 >>>> > > 2014-04-02 11:21:05|23413|vcld:main(167)|lastcheckin time updated >>>> > > for >>>> > > management node 1: 2014-04-02 11:21:05 >>>> > > >>>> > > |23809|94:94|reload| ---- WARNING ---- >>>> > > |23809|94:94|reload| 2014-04-02 >>>> > > 11:21:07|23809|94:94|reload|vSphere_SDK.pm:delete_file(1604)|failed >>>> > > to >>>> > > delete file: [vcl_workspace] vcl-n-001_27-v8, error: >>>> > > |23809|94:94|reload| SOAP Fault: >>>> > > |23809|94:94|reload| ----------- >>>> > > |23809|94:94|reload| Fault string: Cannot delete file >>>> > > [vcl_workspace] >>>> > > vcl-n-001_27-v8 >>>> > > |23809|94:94|reload| Fault detail: CannotDeleteFile >>>> > > |23809|94:94|reload| ( 0) vSphere_SDK.pm, delete_file (line: 1604) >>>> > > |23809|94:94|reload| (-1) VMware.pm, delete_vm (line: 5583) >>>> > > |23809|94:94|reload| (-2) VMware.pm, remove_existing_vms (line: >>>> > > 1612) >>>> > > |23809|94:94|reload| (-3) VMware.pm, load (line: 469) >>>> > > |23809|94:94|reload| (-4) new.pm, reload_image (line: 671) >>>> > > |23809|94:94|reload| (-5) new.pm, process (line: 291) >>>> > > >>>> > > >>>> > > >>>> > > >>>> > > >>>> > > >>>> > > On Wed, Apr 2, 2014 at 11:29 AM, David DeMizio <[email protected]> >>>> > > wrote: >>>> > >> >>>> > >> I have not been using VCL for about a week or so and all of a >>>> > >> sudden I >>>> > >> can't reload images. Below is part of the log. Any ideas? >>>> > >> >>>> > >> VM is still running after attempting to delete all existing >>>> > >> matching VMs: >>>> > >> vcl-n-004 (10.10.12.44), unable to determine vmx file path >>>> > >> >>>> > >> ------------------------------------------------------------------------ >>>> > >> time: 2014-04-02 11:07:13 >>>> > >> caller: VMware.pm:remove_existing_vms(1629) >>>> > >> ( 0) VMware.pm, remove_existing_vms (line: 1629) >>>> > >> (-1) VMware.pm, load (line: 469) >>>> > >> (-2) new.pm, reload_image (line: 671) >>>> > >> (-3) new.pm, process (line: 291) >>>> > >> (-4) vcld, make_new_child (line: 571) >>>> > >> (-5) vcld, main (line: 350) >>>> > >> >>>> > >> ------------------------------------------------------------------------ >>>> > >> >>>> > >> reservation PID: 22252 >>>> > >> parent vcld PID: 23413 >>>> > >> >>>> > >> request ID: 91 >>>> > >> reservation ID: 91 >>>> > >> request state/laststate: reload/inuse >>>> > >> request start time: 2014-04-02 10:58:50 >>>> > >> request end time: 2014-04-02 11:28:50 >>>> > >> for imaging: no >>>> > >> log ID: none >>>> > >> >>>> > >> computer: vcl-n-004 >>>> > >> computer id: 7 >>>> > >> computer type: virtualmachine >>>> > >> computer eth0 MAC address: 00:50:56:00:A0:04 >>>> > >> computer eth1 MAC address: <undefined> >>>> > >> computer private IP address: 10.10.12.44 >>>> > >> computer public IP address: 10.10.11.52 >>>> > >> computer in block allocation: no >>>> > >> provisioning module: VCL::Module::Provisioning::VMware::VMware >>>> > >> >>>> > >> >>>> > >> vm host ID: 2 >>>> > >> vm host computer ID: 9 >>>> > >> vm profile: VMware vCenter >>>> > >> vm profile VM path: /vmfs/volumes/vcl_workspace >>>> > >> vm profile repository path: <undefined> >>>> > >> vm profile datastore path: /vmfs/volumes/vcl_master >>>> > >> vm profile disk type: shared >>>> > >> >>>> > >> image: vmwarewin7-SocialScience27-v8 >>>> > >> image display name: SSRL >>>> > >> image ID: 27 >>>> > >> image revision ID: 45 >>>> > >> image size: 43138 MB >>>> > >> use Sysprep: no >>>> > >> root access: yes >>>> > >> image owner ID: 1 >>>> > >> image owner affiliation: Local >>>> > >> image revision date created: 2014-03-06 10:00:57 >>>> > >> image revision production: yes >>>> > >> OS module: VCL::Module::OS::Windows::Version_6::7 >>>> > >> image revision comments: Added Labs Shortcut to Desktop >>>> > >> >>>> > >> user: vclreload >>>> > >> user name: vcl reload >>>> > >> user ID: 2 >>>> > >> user affiliation: Local >>>> > >> >>>> > >> ------------------------------------------------------------------------ >>>> > >> RECENT LOG ENTRIES FOR THIS PROCESS: >>>> > >> 2014-04-02 >>>> > >> >>>> > >> 11:07:09|22252|91:91|reload|VMware.pm:get_active_vmx_file_path(1026)|ignoring >>>> > >> vcl-n-001_27-v8.vmx because MAC addresses do not match the ones >>>> > >> being used >>>> > >> by vcl-n-004 >>>> > >> 2014-04-02 >>>> > >> 11:07:09|22252|91:91|reload|VMware.pm:get_vmx_info(5313)|attempting >>>> > >> to >>>> > >> retrieve info from vmx file: >>>> > >> /vmfs/volumes/vcl_workspace/vcl-n-002_27-v8/vcl-n-002_27-v8.vmx >>>> > >> 2014-04-02 >>>> > >> >>>> > >> 11:07:09|22252|91:91|reload|Module.pm:code_loop_timeout(887)|attempting >>>> > >> to >>>> > >> copy file from VM host to management node: >>>> > >> nc-vcenter.network.ncf.edu:'[vcl_workspace] >>>> > >> vcl-n-002_27-v8/vcl-n-002_27-v8.vmx' >>>> > >> >>>> > >> >>>> > > >>>> > >>>> > >>>> > >>>> > -- >>>> > http://www.di.uminho.pt/~apa/email/cartao_virtual_email_aaragao.png >>>> > >>>> >>> >> >
