One point to add, not sure if it will help but If I unregister the Vm and delete from disk using the vsphere client and then set the image to "noimage" in the VCL DB , I can load the image fine using reload from the VCL frontend. The issue happens when I create a reservation which works but when I delete the reservation it doesn't reload.
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 Thu, Apr 3, 2014 at 1:13 PM, David DeMizio <[email protected]> wrote: > Hi Andy, > > I see a bunch of "get_registered_vms" like the line below > > |29339|116:116|reload| (-3) vSphere_SDK.pm, get_registered_vms (line: 208) > |29339|116:116|reload| (-4) VMware.pm, get_vmx_file_paths (line: 5246) > |29339|116:116|reload| (-5) VMware.pm, remove_existing_vms (line: 1556) > > > |29339|116:116|reload| ---- WARNING ---- > |29339|116:116|reload| 2014-04-03 > 11:22:24|29339|116:116|reload|VMware.pm:_get_datastore_root_normal_path(6916)|failed > to determine datastore root normal path, unable to determine datastore > name: [Old VM's] VSA FOM/VSA FOM.vmx > |29339|116:116|reload| ( 0) VMware.pm, _get_datastore_root_normal_path > (line: 6916) > |29339|116:116|reload| (-1) VMware.pm, _get_normal_path (line: 7006) > |29339|116:116|reload| (-2) vSphere_SDK.pm, get_registered_vms (line: 208) > |29339|116:116|reload| (-3) VMware.pm, get_vmx_file_paths (line: 5246) > > in the client, I do see vcl-n-001:vmwarewin7...... and it's powered on > still > > output from command: > > ~ # ps -c |grep '/bin/vmx .*vcl-n-001' > 8239365 8239365 vmx /bin/vmx -s sched.group=host/user -# > product=2;name=VMware > ESX;version=5.5.0;buildnumber=1331820;licensename=VMware ESX > Server;licenseversion=5.0; -@ duplex=3;msgs=ui > /vmfs/volumes/5284a6b9-9d90bf28-a89e-d89d67260538/vcl-n-001_27-v7/vcl-n-001_27-v7.vmx > 8239370 8239365 vmx-vthread-4:vcl-n-001:vmwarewin7-SocialScience27-v7 > (shared) /bin/vmx -s sched.group=host/user -# product=2;name=VMware > ESX;version=5.5.0;buildnumber=1331820;licensename=VMware ESX > Server;licenseversion=5.0; -@ duplex=3;msgs=ui > /vmfs/volumes/5284a6b9-9d90bf28-a89e-d89d67260538/vcl-n-001_27-v7/vcl-n-001_27-v7.vmx > 8239371 8239365 vmx-mks:vcl-n-001:vmwarewin7-SocialScience27-v7 (shared) > /bin/vmx -s sched.group=host/user -# product=2;name=VMware > ESX;version=5.5.0;buildnumber=1331820;licensename=VMware ESX > Server;licenseversion=5.0; -@ duplex=3;msgs=ui > /vmfs/volumes/5284a6b9-9d90bf28-a89e-d89d67260538/vcl-n-001_27-v7/vcl-n-001_27-v7.vmx > 8239372 8239365 vmx-svga:vcl-n-001:vmwarewin7-SocialScience27-v7 (shared) > /bin/vmx -s sched.group=host/user -# product=2;name=VMware > ESX;version=5.5.0;buildnumber=1331820;licensename=VMware ESX > Server;licenseversion=5.0; -@ duplex=3;msgs=ui > /vmfs/volumes/5284a6b9-9d90bf28-a89e-d89d67260538/vcl-n-001_27-v7/vcl-n-001_27-v7.vmx > 8239373 8239365 vmx-vcpu-0:vcl-n-001:vmwarewin7-SocialScience27-v7 > (shared) /bin/vmx -s sched.group=host/user -# product=2;name=VMware > ESX;version=5.5.0;buildnumber=1331820;licensename=VMware ESX > Server;licenseversion=5.0; -@ duplex=3;msgs=ui > /vmfs/volumes/5284a6b9-9d90bf28-a89e-d89d67260538/vcl-n-001_27-v7/vcl-n-001_27-v7.vmx > > > > > 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 Thu, Apr 3, 2014 at 12:28 PM, Andy Kurth <[email protected]> wrote: > >> Thanks for the vcld.log output, saw it after I sent my previous >> message. Are there any lines containing "get_registered_vms" in >> vcld.log? This would list the VMs it though was registered and would >> be helpful to determine if VCL is correctly finding registered VMs and >> parsing the names. >> >> What VMs do you see in the vSphere client? Do you don't see any VMs >> named vcl-n-001*? >> >> If you have SSH or console access to the host, try running: >> ps -c |grep '/bin/vmx .*vcl-n-001' >> >> Does this show any running processes? >> >> On Thu, Apr 3, 2014 at 12:11 PM, Andy Kurth <[email protected]> wrote: >> > 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 >> >>>>> > >> >>>>> >> >>>> >> >>> >> >> >> > >
