You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@vcl.apache.org by Roger Herling <Ro...@marist.edu> on 2011/07/15 17:59:26 UTC
why does it take so long to provision a VM that already has the correct
image on it?
Hi all we have been having an issue where all of our vm's are pre loaded
with an image but when you request a reservation the VM is deleted and
reset why is this happening. I thought that the whole purpose of having
the vms ready to go was that provisioning time should only be 1-2 minutes
instead it 5-7.
Roger Herling
Sr. Desktop Administrator
Marist College
Office: 845-575-3347
Cell: 845-240-4298
Re: why does it take so long to provision a VM that already has the correct
image on it?
Posted by Roger Herling <Ro...@marist.edu>.
VMWARE
Roger Herling
Sr. Desktop Administrator
Marist College
Office: 845-575-3347
Cell: 845-240-4298
From: Aaron Peeler <fa...@ncsu.edu>
To: vcl-user@incubator.apache.org
Date: 07/15/2011 12:17 PM
Subject: Re: why does it take so long to provision a VM that
already has the correct image on it?
Hello Roger,
Which provisioning module are you using for your vms? In an older release,
there was a esx.pm module which has this behavior.
Make sure your not using that prov module.
Aaron
On Fri, Jul 15, 2011 at 11:59 AM, Roger Herling <Ro...@marist.edu>
wrote:
Hi all we have been having an issue where all of our vm's are pre loaded
with an image but when you request a reservation the VM is deleted and
reset why is this happening. I thought that the whole purpose of having
the vms ready to go was that provisioning time should only be 1-2 minutes
instead it 5-7.
Roger Herling
Sr. Desktop Administrator
Marist College
Office: 845-575-3347
Cell: 845-240-4298
--
Aaron Peeler
Program Manager
Virtual Computing Lab
NC State University
All electronic mail messages in connection with State business which are
sent to or received by this account are subject to the NC Public Records
Law and may be disclosed to third parties.
Re: why does it take so long to provision a VM that already has the
correct image on it?
Posted by Andy Kurth <an...@ncsu.edu>.
The log output you sent indicates that the VM wasn't responding to SSH so it
was reloded. Make sure the image OS is configured to disable sleep mode.
On Fri, Jul 15, 2011 at 2:05 PM, Roger Herling <Ro...@marist.edu>wrote:
> Hey Andy here you go. I was able to get two Vms to provision within
> 45seconds but those where two that had just been reloaded 10 minutes
> earlier. It appears to only happen when a machine is idle for a while.
>
>
> {421}{computer}{state}{name}
> |20773|455:421|new| computer_state_name = available
> 2011-07-15 14:00:28|20773|455:421|new|utils.pm:get_management_node_id(8740)|environment
> variable: 1
> 2011-07-15 14:00:28|20773|455:421|new|new.pm:process(133)|reservation is
> parent = 1
> 2011-07-15 14:00:28|20773|455:421|new|new.pm:process(134)|preload only = 0
> 2011-07-15 14:00:28|20773|455:421|new|new.pm:process(135)|originating
> request state = new
> 2011-07-15 14:00:28|20773|455:421|new|new.pm:process(136)|originating
> request laststate = new
> 2011-07-15 14:00:28|20773|455:421|new|new.pm:process(137)|originating
> computer state = available
> 2011-07-15 14:00:28|20773|455:421|new|new.pm:process(138)|originating
> computer type = virtualmachine
> 2011-07-15
> 14:00:28|20773|455:421|new|DataStructure.pm:is_parent_reservation(943)|returning
> true: parent reservation ID for this request: 421
> 2011-07-15
> 14:00:28|20773|455:421|new|DataStructure.pm:get_computer_state_name(2227)|attempting
> to retrieve current state of computer vm1202 from the database
> 2011-07-15
> 14:00:28|20773|455:421|new|DataStructure.pm:get_computer_state_name(2258)|retrieved
> current state of computer vm1202 from the database: available
> 2011-07-15
> 14:00:28|20773|455:421|new|DataStructure.pm:_automethod(786)|data structure
> updated: $self->request_data->{reservation}{421}{computer}{state}{name}
> |20773|455:421|new| computer_state_name = available
> 2011-07-15 14:00:28|20773|455:421|new|utils.pm:get_management_node_id(8740)|environment
> variable: 1
> 2011-07-15 14:00:28|20773|455:421|new|new.pm:computer_not_being_used(787)|vm1202
> state is available
> 2011-07-15 14:00:28|20773|455:421|new|new.pm:computer_not_being_used(797)|vm1202
> is available, its state is available
> 2011-07-15 14:00:28|20773|455:421|new|new.pm:process(186)|vm1202 is not
> being used
> 2011-07-15
> 14:00:28|20773|455:421|new|DataStructure.pm:is_parent_reservation(943)|returning
> true: parent reservation ID for this request: 421
> 2011-07-15
> 14:00:28|20773|455:421|new|DataStructure.pm:get_computer_state_name(2227)|attempting
> to retrieve current state of computer vm1202 from the database
> 2011-07-15
> 14:00:28|20773|455:421|new|DataStructure.pm:get_computer_state_name(2258)|retrieved
> current state of computer vm1202 from the database: available
> 2011-07-15
> 14:00:28|20773|455:421|new|DataStructure.pm:_automethod(786)|data structure
> updated: $self->request_data->{reservation}{421}{computer}{state}{name}
> |20773|455:421|new| computer_state_name = available
> 2011-07-15 14:00:28|20773|455:421|new|utils.pm:get_management_node_id(8740)|environment
> variable: 1
> 2011-07-15 14:00:28|20773|455:421|new|new.pm:reload_image(529)|calling
> VCL::Module::Provisioning::VMware::VMware->node_status()
> 2011-07-15 14:00:29|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
> computer=13, statuscheck, checking status of node
> 2011-07-15 14:00:29|20773|455:421|new|utils.pm:nmap_port(2707)|port 22 is
> closed on vm1202
> 2011-07-15 14:00:29|20773|455:421|new|utils.pm:nmap_port(2707)|port 24 is
> closed on vm1202
> 2011-07-15 14:00:29|20773|455:421|new|OS.pm:is_ssh_responding(416)|vm1202
> is NOT responding to SSH, ports 22 or 24 are both closed
> 2011-07-15 14:00:29|20773|455:421|new|VMware.pm:node_status(738)|VM vm1202
> is not responding to SSH, returning 'RELOAD'
> 2011-07-15 14:00:29|20773|455:421|new|new.pm:reload_image(544)|node_status
> returned a hash reference
> 2011-07-15 14:00:29|20773|455:421|new|new.pm:reload_image(549)|node_status
> hash reference contains key {status}=RELOAD
> 2011-07-15 14:00:29|20773|455:421|new|new.pm:reload_image(624)|node status
> is RELOAD, vm1202 will be reloaded
> 2011-07-15 14:00:29|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
> computer=13, loadimageblade, vm1202 must be reloaded with
> vmwarewin7-MSProjectWin76474-v3
> 2011-07-15 14:00:29|20773|455:421|new|new.pm:reload_image(638)|calling
> VCL::Module::Provisioning::VMware::VMware->does_image_exist()
> 2011-07-15
> 14:00:29|20773|455:421|new|VMware.pm:does_image_exist(2937)|image exists in
> the non-persistent directory on the VM host:
> /vmfs/volumes/nfs-datastore/vmwarewin7-MSProjectWin76474-v3/vmwarewin7-MSProjectWin76474-v3.vmdk
> 2011-07-15 14:00:29|20773|455:421|new|new.pm:reload_image(641)|vmwarewin7-MSProjectWin76474-v3
> exists on this management node
> 2011-07-15 14:00:29|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
> computer=13, doesimageexists, confirmed image exists
> 2011-07-15 14:00:29|20773|455:421|new|utils.pm:update_computer_state(2091)|computer
> 13 state updated to: reloading
> 2011-07-15 14:00:29|20773|455:421|new|new.pm:reload_image(674)|computer
> vm1202 state set to reloading
> 2011-07-15 14:00:29|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
> computer=13, info, computer state updated to reloading
> 2011-07-15 14:00:29|20773|455:421|new|new.pm:reload_image(685)|calling
> VCL::Module::Provisioning::VMware::VMware->load() subroutine
> 2011-07-15 14:00:29|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
> computer=13, info, calling VCL::Module::Provisioning::VMware::VMware->load()
> subroutine
> 2011-07-15 14:00:29|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
> computer=13, doesimageexists, image exists vmwarewin7-MSProjectWin76474-v3
> 2011-07-15 14:00:29|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
> computer=13, startload, vm1202 vmwarewin7-MSProjectWin76474-v3
> 2011-07-15
> 14:00:29|20773|455:421|new|VMware.pm:get_vmx_file_paths(3333)|attempting to
> find existing vmx files on the VM host
> 2011-07-15 14:00:29|20773|455:421|new|Linux.pm:find_files(1933)|attempting
> to find files on blade12, base directory path:
> '/vmfs/volumes/local-datastore/', pattern: *.vmx, command: find
> "/vmfs/volumes/local-datastore/" -type f -iname "*.vmx"
> 2011-07-15 14:00:30|20773|455:421|new|Linux.pm:find_files(1951)|matching
> file count: 7
> 2011-07-15
> 14:00:31|20773|455:421|new|VMware.pm:get_vmx_file_paths(3344)|found 7 unique
> vmx files on VM host:
> |20773|455:421|new|
> /vmfs/volumes/local-datastore/vm1201_74-v3/vm1201_74-v3.vmx
> |20773|455:421|new|
> /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
> |20773|455:421|new|
> /vmfs/volumes/local-datastore/vm1203_74-v3/vm1203_74-v3.vmx
> |20773|455:421|new|
> /vmfs/volumes/local-datastore/vm1204_74-v3/vm1204_74-v3.vmx
> |20773|455:421|new|
> /vmfs/volumes/local-datastore/vm1205_74-v3/vm1205_74-v3.vmx
> |20773|455:421|new|
> /vmfs/volumes/local-datastore/vm1206_74-v3/vm1206_74-v3.vmx
> |20773|455:421|new|
> /vmfs/volumes/local-datastore/vm1206_cs5fix/vm1206_cs5fix.vmx
> 2011-07-15
> 14:00:31|20773|455:421|new|VMware.pm:remove_existing_vms(1129)|ignoring
> existing vmx directory: vm1201_74-v3
> 2011-07-15
> 14:00:31|20773|455:421|new|VMware.pm:remove_existing_vms(1114)|found
> existing vmx directory with that appears to match vm1202:
> /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
> 2011-07-15
> 14:00:31|20773|455:421|new|VMware.pm:get_vmx_info(3403)|attempting to
> retrieve info from vmx file:
> /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
> 2011-07-15
> 14:00:31|20773|455:421|new|Linux.pm:get_file_contents(1576)|retrieved 88
> lines from file on blade12:
> '/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx'
> 2011-07-15 14:00:31|20773|455:421|new|VMware.pm:delete_vm(3510)|attempting
> to delete VM: /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
> 2011-07-15
> 14:00:31|20773|455:421|new|VMware.pm:get_vmx_info(3399)|returning previously
> retrieved info from vmx file:
> /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
> 2011-07-15 14:00:32|30621|vcld:main(166)|lastcheckin time updated for
> management node 1: 2011-07-15 14:00:32
> 2011-07-15 14:00:32|20773|455:421|new|VMware.pm:is_vm_registered(2783)|VM
> is registered: /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
> 2011-07-15 14:00:33|20773|455:421|new|VIM_SSH.pm:get_vm_power_state(954)|VM
> is powered on: /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
> 2011-07-15
> 14:00:33|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
> remote IP is not defined
> 2011-07-15
> 14:00:33|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
> remote IP is not defined
> 2011-07-15 14:00:37|30621|vcld:main(166)|lastcheckin time updated for
> management node 1: 2011-07-15 14:00:37
> 2011-07-15
> 14:00:38|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
> remote IP is not defined
> 2011-07-15
> 14:00:38|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
> remote IP is not defined
> 2011-07-15
> 14:00:40|20773|455:421|new|VIM_SSH.pm:_wait_for_task(830)|checking status of
> task: haTask-3456-vim.VirtualMachine.powerOff-20732
> 2011-07-15 14:00:40|20773|455:421|new|VIM_SSH.pm:_wait_for_task(843)|task
> completed successfully: haTask-3456-vim.VirtualMachine.powerOff-20732
> 2011-07-15 14:00:40|20773|455:421|new|VIM_SSH.pm:vm_power_off(1112)|powered
> off VM: /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
> 2011-07-15 14:00:42|20773|455:421|new|VMware.pm:is_vm_registered(2788)|VM
> is not registered:
> '/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx', registered
> paths:
> |20773|455:421|new|
> /vmfs/volumes/local-datastore/vm1206_74-v3/vm1206_74-v3.vmx
> |20773|455:421|new|
> /vmfs/volumes/local-datastore/vm1203_74-v3/vm1203_74-v3.vmx
> |20773|455:421|new|
> /vmfs/volumes/local-datastore/vm1204_74-v3/vm1204_74-v3.vmx
> |20773|455:421|new|
> /vmfs/volumes/local-datastore/vm1205_74-v3/vm1205_74-v3.vmx
> |20773|455:421|new|
> /vmfs/volumes/local-datastore/vm1201_74-v3/vm1201_74-v3.vmx
> 2011-07-15
> 14:00:42|20773|455:421|new|VIM_SSH.pm:vm_unregister(1244)|unregistered VM:
> /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx (ID: 3456)
> 2011-07-15 14:00:42|20773|455:421|new|VMware.pm:delete_vm(3533)|checking if
> existing VM's vmdk file should be deleted:
> |20773|455:421|new| vmdk file path:
> /vmfs/volumes/nfs-datastore/vmwarewin7-MSProjectWin76474-v3/vmwarewin7-MSProjectWin76474-v3.vmdk
> |20773|455:421|new| vmx storage identier key: scsi0:0
> |20773|455:421|new| disk mode: independent-nonpersistent
> 2011-07-15 14:00:42|20773|455:421|new|VMware.pm:delete_vm(3543)|mode of
> vmdk file: independent-nonpersistent, vmdk directory will NOT be deleted
> 2011-07-15 14:00:42|20773|455:421|new|VMware.pm:delete_vm(3556)|attempt
> 1/5: attempting to delete vmx directory:
> /vmfs/volumes/local-datastore/vm1202_74-v3
> 2011-07-15 14:00:42|30621|vcld:main(166)|lastcheckin time updated for
> management node 1: 2011-07-15 14:00:42
> 2011-07-15 14:00:42|20773|455:421|new|Linux.pm:delete_file(1410)|deleted
> '/vmfs/volumes/local-datastore/vm1202_74-v3' on blade12
> 2011-07-15 14:00:43|20773|455:421|new|Linux.pm:file_exists(1341)|file or
> directory does not exist on blade12:
> '/vmfs/volumes/local-datastore/vm1202_74-v3'
> 2011-07-15 14:00:43|20773|455:421|new|Linux.pm:delete_file(1424)|confirmed
> file does not exist on blade12: '/vmfs/volumes/local-datastore/vm1202_74-v3'
> 2011-07-15 14:00:43|20773|455:421|new|VMware.pm:delete_vm(3558)|deleted VM:
> /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
> 2011-07-15
> 14:00:43|20773|455:421|new|VMware.pm:remove_existing_vms(1129)|ignoring
> existing vmx directory: vm1203_74-v3
> 2011-07-15
> 14:00:43|20773|455:421|new|VMware.pm:remove_existing_vms(1129)|ignoring
> existing vmx directory: vm1204_74-v3
> 2011-07-15
> 14:00:43|20773|455:421|new|VMware.pm:remove_existing_vms(1129)|ignoring
> existing vmx directory: vm1205_74-v3
> 2011-07-15
> 14:00:43|20773|455:421|new|VMware.pm:remove_existing_vms(1129)|ignoring
> existing vmx directory: vm1206_74-v3
> 2011-07-15
> 14:00:43|20773|455:421|new|VMware.pm:remove_existing_vms(1129)|ignoring
> existing vmx directory: vm1206_cs5fix
> 2011-07-15
> 14:00:43|20773|455:421|new|VMware.pm:get_repository_vmdk_base_directory_path(2655)|repository
> path is not set for the VM profile, using management node install path:
> /install/vmware_images
> 2011-07-15
> 14:00:43|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
> remote IP is not defined
> 2011-07-15
> 14:00:43|20773|455:421|new|VMware.pm:get_vmhost_product_name(4090)|VMware
> product being used on VM host blade12: 'VMware ESXi 4.1.0 build-260247'
> 2011-07-15
> 14:00:43|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
> remote IP is not defined
> 2011-07-15
> 14:00:44|20773|455:421|new|VIM_SSH.pm:_get_datastore_names(477)|retrieved
> datastore names: local-datastore, nfs-datastore
> 2011-07-15
> 14:00:45|20773|455:421|new|VIM_SSH.pm:get_virtual_disk_type(1370)|vmwarewin7-MSProjectWin76474-v3.vmdk
> disk type: FlatVer2
> 2011-07-15
> 14:00:45|20773|455:421|new|VMware.pm:check_vmdk_disk_type(1657)|flat virtual
> disk (FlatVer2) does not need to be converted for VMware ESXi 4.1.0
> build-260247
> 2011-07-15 14:00:45|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
> computer=13, transfervm, copied vmwarewin7-MSProjectWin76474-v3 to vm1202
> 2011-07-15
> 14:00:45|20773|455:421|new|VMware.pm:get_vm_os_configuration(3212)|retrieved
> default VM configuration for OS: 7-x86
> |20773|455:421|new| : {
> |20773|455:421|new| : "ethernet-virtualDev" => "e1000",
> |20773|455:421|new| : "guestOS" => "winvista",
> |20773|455:421|new| : "scsi-virtualDev" => "lsiLogic"
> |20773|455:421|new| : }
> 2011-07-15 14:00:47|30621|vcld:main(166)|lastcheckin time updated for
> management node 1: 2011-07-15 14:00:47
> 2011-07-15
> 14:00:47|20773|455:421|new|VIM_SSH.pm:get_virtual_disk_controller_type(1521)|retrieved
> controller type for vmwarewin7-MSProjectWin76474-v3.vmdk: 'LsiLogic'
> 2011-07-15
> 14:00:47|20773|455:421|new|VMware.pm:get_vm_disk_adapter_type(3073)|retrieved
> VM disk adapter type from api object: LsiLogic
> 2011-07-15
> 14:00:48|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
> remote IP is not defined
> 2011-07-15
> 14:00:48|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
> remote IP is not defined
> 2011-07-15
> 14:00:49|20773|455:421|new|VIM_SSH.pm:get_virtual_disk_hardware_version(1669)|retrieved
> hardware version for vmwarewin7-MSProjectWin76474-v3.vmdk: '7'
> 2011-07-15
> 14:00:49|20773|455:421|new|VMware.pm:get_vm_virtual_hardware_version(3120)|retrieved
> hardware version from api object: 7
> 2011-07-15
> 14:00:49|20773|455:421|new|VMware.pm:get_vm_virtual_hardware_version(3158)|returning
> hardware version: 7
> 2011-07-15
> 14:00:49|20773|455:421|new|Linux.pm:create_directory(1475)|directory either
> created or already exists on blade12:
> '/vmfs/volumes/local-datastore/vm1202_74-v3'
> 2011-07-15 14:00:49|20773|455:421|new|VMware.pm:prepare_vmx(1222)|vm info:
> |20773|455:421|new| display name: vm1202:vmwarewin7-MSProjectWin76474-v3
> (nonpersistent)
> |20773|455:421|new| image ID: 74
> |20773|455:421|new| imagerevision ID: 81
> |20773|455:421|new| vmx path:
> /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
> |20773|455:421|new| vmx directory name: vm1202_74-v3
> |20773|455:421|new| vmx directory path:
> /vmfs/volumes/local-datastore/vm1202_74-v3
> |20773|455:421|new| vmdk file path:
> /vmfs/volumes/nfs-datastore/vmwarewin7-MSProjectWin76474-v3/vmwarewin7-MSProjectWin76474-v3.vmdk
> |20773|455:421|new| persistent: 0
> |20773|455:421|new| computer ID: 13
> |20773|455:421|new| computer name: vm1202
> |20773|455:421|new| image name: vmwarewin7-MSProjectWin76474-v3
> |20773|455:421|new| guest OS: winvista
> |20773|455:421|new| virtual hardware version: 7
> |20773|455:421|new| RAM: 4096
> |20773|455:421|new| CPU count: 2
> |20773|455:421|new| ethernet adapter type: e1000
> |20773|455:421|new| virtual switch 0: Private
> |20773|455:421|new| eth0 MAC address: 00:50:56:12:02:01
> |20773|455:421|new| virtual switch 1: Public
> |20773|455:421|new| eth1 MAC address: 00:50:56:12:02:02
> |20773|455:421|new| disk adapter type: LsiLogic
> |20773|455:421|new| disk mode: independent-nonpersistent
> |20773|455:421|new| disk write through: FALSE
> 2011-07-15 14:00:49|20773|455:421|new|VMware.pm:prepare_vmx(1386)|image
> project is: vcl, additional network adapters will not be configured
> 2011-07-15 14:00:49|20773|455:421|new|VMware.pm:prepare_vmx(1389)|vmx
> parameters:
> |20773|455:421|new| : {
> |20773|455:421|new| : "#computer_id" => 13,
> |20773|455:421|new| : "#image_id" => 74,
> |20773|455:421|new| : "#imagerevision_id" => 81,
> |20773|455:421|new| : ".encoding" => "UTF-8",
> |20773|455:421|new| : "config.version" => 8,
> |20773|455:421|new| : "disk.locking" => "false",
> |20773|455:421|new| : "displayName" =>
> "vm1202:vmwarewin7-MSProjectWin76474-v3 (nonpersistent)",
> |20773|455:421|new| : "ethernet0.address" => "00:50:56:12:02:01",
> |20773|455:421|new| : "ethernet0.addressType" => "static",
> |20773|455:421|new| : "ethernet0.networkName" => "Private",
> |20773|455:421|new| : "ethernet0.present" => "TRUE",
> |20773|455:421|new| : "ethernet0.virtualDev" => "e1000",
> |20773|455:421|new| : "ethernet1.address" => "00:50:56:12:02:02",
> |20773|455:421|new| : "ethernet1.addressType" => "static",
> |20773|455:421|new| : "ethernet1.networkName" => "Public",
> |20773|455:421|new| : "ethernet1.present" => "TRUE",
> |20773|455:421|new| : "ethernet1.virtualDev" => "e1000",
> |20773|455:421|new| : "floppy0.present" => "FALSE",
> |20773|455:421|new| : "guestOS" => "winvista",
> |20773|455:421|new| : "gui.exitOnCLIHLT" => "TRUE",
> |20773|455:421|new| : "memsize" => 4096,
> |20773|455:421|new| : "msg.autoAnswer" => "TRUE",
> |20773|455:421|new| : "numvcpus" => 2,
> |20773|455:421|new| : "pciBridge0.present" => "TRUE",
> |20773|455:421|new| : "pciBridge4.functions" => 8,
> |20773|455:421|new| : "pciBridge4.present" => "TRUE",
> |20773|455:421|new| : "pciBridge4.virtualDev" => "pcieRootPort",
> |20773|455:421|new| : "pciBridge5.functions" => 8,
> |20773|455:421|new| : "pciBridge5.present" => "TRUE",
> |20773|455:421|new| : "pciBridge5.virtualDev" => "pcieRootPort",
> |20773|455:421|new| : "pciBridge6.functions" => 8,
> |20773|455:421|new| : "pciBridge6.present" => "TRUE",
> |20773|455:421|new| : "pciBridge6.virtualDev" => "pcieRootPort",
> |20773|455:421|new| : "pciBridge7.functions" => 8,
> |20773|455:421|new| : "pciBridge7.present" => "TRUE",
> |20773|455:421|new| : "pciBridge7.virtualDev" => "pcieRootPort",
> |20773|455:421|new| : "powerType.powerOff" => "soft",
> |20773|455:421|new| : "powerType.powerOn" => "hard",
> |20773|455:421|new| : "powerType.reset" => "soft",
> |20773|455:421|new| : "powerType.suspend" => "hard",
> |20773|455:421|new| : "scsi0.present" => "TRUE",
> |20773|455:421|new| : "scsi0.virtualDev" => "LsiLogic",
> |20773|455:421|new| : "scsi0:0.fileName" =>
> "/vmfs/volumes/nfs-datastore/vmwarewin7-MSProjectWin76474-v3/vmwarewin7-MSProjectWin76474-v3.vmdk",
> |20773|455:421|new| : "scsi0:0.mode" => "independent-nonpersistent",
> |20773|455:421|new| : "scsi0:0.present" => "TRUE",
> |20773|455:421|new| : "scsi0:0.writeThrough" => "FALSE",
> |20773|455:421|new| : "snapshot.disabled" => "TRUE",
> |20773|455:421|new| : "svga.vramSize" => 33554432,
> |20773|455:421|new| : "toolScripts.afterPowerOn" => "TRUE",
> |20773|455:421|new| : "toolScripts.afterResume" => "TRUE",
> |20773|455:421|new| : "toolScripts.beforePowerOff" => "TRUE",
> |20773|455:421|new| : "toolScripts.beforeSuspend" => "TRUE",
> |20773|455:421|new| : "tools.remindInstall" => "TRUE",
> |20773|455:421|new| : "tools.syncTime" => "FALSE",
> |20773|455:421|new| : "uuid.action" => "keep",
> |20773|455:421|new| : "virtualHW.version" => 7,
> |20773|455:421|new| : "vmci0.present" => "TRUE"
> |20773|455:421|new| : }
> 2011-07-15 14:00:49|20773|455:421|new|VMware.pm:prepare_vmx(1400)|created
> temporary vmx file: /tmp/vm1202_74-v3.vmx
> 2011-07-15
> 14:00:49|20773|455:421|new|Linux.pm:create_directory(1475)|directory either
> created or already exists on blade12:
> '/vmfs/volumes/local-datastore/vm1202_74-v3'
> 2011-07-15 14:00:49|20773|455:421|new|utils.pm:run_scp_command(5671)|attempt
> 1/3: executing SCP command: /usr/bin/scp -B -i /etc/vcl/vcl.key -P 22 -p -r
> /tmp/vm1202_74-v3.vmx
> blade12:"/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx" 2>&1
> 2011-07-15 14:00:50|20773|455:421|new|utils.pm:run_scp_command(5722)|scp
> successful: attempt 1/3, exit status: 0, output:
> 2011-07-15 14:00:50|20773|455:421|new|Linux.pm:copy_file_to(1740)|copied
> file from management node to blade12: '/tmp/vm1202_74-v3.vmx' -->
> blade12:'/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx'
> 2011-07-15 14:00:50|20773|455:421|new|VMware.pm:prepare_vmx(1409)|created
> vmx file on VM host:
> /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
> 2011-07-15 14:00:50|20773|455:421|new|VMware.pm:prepare_vmx(1412)|deleted
> temporary vmx file: /tmp/vm1202_74-v3.vmx
> 2011-07-15 14:00:50|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
> computer=13, vmsetupconfig, prepared vmx file
> 2011-07-15 14:00:50|20773|455:421|new|VMware.pm:is_vm_registered(2788)|VM
> is not registered:
> '/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx', registered
> paths:
> |20773|455:421|new|
> /vmfs/volumes/local-datastore/vm1206_74-v3/vm1206_74-v3.vmx
> |20773|455:421|new|
> /vmfs/volumes/local-datastore/vm1203_74-v3/vm1203_74-v3.vmx
> |20773|455:421|new|
> /vmfs/volumes/local-datastore/vm1204_74-v3/vm1204_74-v3.vmx
> |20773|455:421|new|
> /vmfs/volumes/local-datastore/vm1205_74-v3/vm1205_74-v3.vmx
> |20773|455:421|new|
> /vmfs/volumes/local-datastore/vm1201_74-v3/vm1201_74-v3.vmx
> 2011-07-15 14:00:52|30621|vcld:main(166)|lastcheckin time updated for
> management node 1: 2011-07-15 14:00:52
> 2011-07-15 14:00:53|20773|455:421|new|VMware.pm:is_vm_registered(2783)|VM
> is registered: /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
> 2011-07-15
> 14:00:53|20773|455:421|new|VIM_SSH.pm:vm_register(1172)|registered VM:
> '/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx'
> 2011-07-15
> 14:00:53|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
> remote IP is not defined
> 2011-07-15
> 14:00:53|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
> remote IP is not defined
> 2011-07-15 14:00:57|30621|vcld:main(166)|lastcheckin time updated for
> management node 1: 2011-07-15 14:00:57
> 2011-07-15
> 14:00:58|20773|455:421|new|VIM_SSH.pm:_wait_for_task(830)|checking status of
> task: haTask-3792-vim.VirtualMachine.powerOn-20780
> 2011-07-15
> 14:00:58|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
> remote IP is not defined
> 2011-07-15
> 14:00:58|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
> remote IP is not defined
> 2011-07-15 14:00:58|20773|455:421|new|VIM_SSH.pm:_wait_for_task(843)|task
> completed successfully: haTask-3792-vim.VirtualMachine.powerOn-20780
> 2011-07-15 14:00:58|20773|455:421|new|VIM_SSH.pm:vm_power_on(1037)|powered
> on VM: /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
> 2011-07-15 14:00:58|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
> computer=13, startvm, registered and powered on vm1202
> 2011-07-15 14:00:58|20773|455:421|new|Version_6.pm:post_load(185)|beginning
> Windows version 6 post-load tasks
> 2011-07-15 14:00:58|20773|455:421|new|Version_6.pm:post_load(193)|calling
> parent class post_load() subroutine
> 2011-07-15 14:00:58|20773|455:421|new|Windows.pm:post_load(550)|beginning
> Windows post-load tasks on vm1202
> 2011-07-15 14:00:59|20773|455:421|new|utils.pm:nmap_port(2707)|port 22 is
> closed on vm1202
> 2011-07-15 14:00:59|20773|455:421|new|utils.pm:nmap_port(2707)|port 24 is
> closed on vm1202
> 2011-07-15 14:00:59|20773|455:421|new|OS.pm:is_ssh_responding(416)|vm1202
> is NOT responding to SSH, ports 22 or 24 are both closed
> 2011-07-15 14:00:59|20773|455:421|new|OS.pm:wait_for_response(477)|waiting
> 15 seconds for vm1202 to boot
> 2011-07-15 14:01:02|30621|vcld:main(166)|lastcheckin time updated for
> management node 1: 2011-07-15 14:01:02
> 2011-07-15
> 14:01:03|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
> remote IP is not defined
> 2011-07-15
> 14:01:03|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
> remote IP is not defined
> 2011-07-15 14:01:03|20723|454:420|reserved|reserved.pm:process(243)|attempt
> 10 of 180, user has not acknowleged
> 2011-07-15 14:01:07|30621|vcld:main(166)|lastcheckin time updated for
> management node 1: 2011-07-15 14:01:07
> 2011-07-15
> 14:01:08|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
> remote IP is not defined
> 2011-07-15
> 14:01:08|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
> remote IP is not defined
> 2011-07-15 14:01:12|30621|vcld:main(166)|lastcheckin time updated for
> management node 1: 2011-07-15 14:01:12
> 2011-07-15
> 14:01:13|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
> remote IP is not defined
> 2011-07-15
> 14:01:13|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
> remote IP is not defined
> 2011-07-15 14:01:14|20773|455:421|new|OS.pm:wait_for_response(479)|waited
> 15 seconds for vm1202 to boot
> 2011-07-15 14:01:14|20773|455:421|new|OS.pm:wait_for_response(483)|waiting
> for vm1202 to respond to SSH, maximum of 300 seconds
> 2011-07-15
> 14:01:14|20773|455:421|new|Module.pm:code_loop_timeout(396)|waiting for
> vm1202 to respond to SSH, maximum of 300 seconds
> 2011-07-15
> 14:01:14|20773|455:421|new|Module.pm:code_loop_timeout(413)|attempt 1:
> waiting for vm1202 to respond to SSH
> 2011-07-15 14:01:14|20773|455:421|new|utils.pm:nmap_port(2707)|port 22 is
> closed on vm1202
> 2011-07-15 14:01:14|20773|455:421|new|utils.pm:nmap_port(2707)|port 24 is
> closed on vm1202
> 2011-07-15 14:01:14|20773|455:421|new|OS.pm:is_ssh_responding(416)|vm1202
> is NOT responding to SSH, ports 22 or 24 are both closed
> 2011-07-15
> 14:01:14|20773|455:421|new|Module.pm:code_loop_timeout(409)|attempt 1: code
> returned false, seconds elapsed/remaining: 0/300, sleeping for 15 seconds
> 2011-07-15 14:01:17|30621|vcld:main(166)|lastcheckin time updated for
> management node 1: 2011-07-15 14:01:17
> 2011-07-15
> 14:01:18|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
> remote IP is not defined
> 2011-07-15 14:01:18|20495|453:419|reserved|reserved.pm:process(243)|attempt
> 20 of 180, user has not acknowleged
> 2011-07-15
> 14:01:18|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
> remote IP is not defined
> 2011-07-15 14:01:22|30621|vcld:main(166)|lastcheckin time updated for
> management node 1: 2011-07-15 14:01:22
> 2011-07-15
> 14:01:23|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
> remote IP is not defined
> 2011-07-15
> 14:01:23|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
> remote IP is not defined
> 2011-07-15 14:01:27|30621|vcld:main(166)|lastcheckin time updated for
> management node 1: 2011-07-15 14:01:27
> 2011-07-15
> 14:01:28|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
> remote IP is not defined
> 2011-07-15
> 14:01:28|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
> remote IP is not defined
> 2011-07-15
> 14:01:29|20773|455:421|new|Module.pm:code_loop_timeout(413)|attempt 2:
> waiting for vm1202 to respond to SSH
> 2011-07-15 14:01:30|20773|455:421|new|utils.pm:nmap_port(2707)|port 22 is
> closed on vm1202
> 2011-07-15 14:01:30|20773|455:421|new|utils.pm:nmap_port(2707)|port 24 is
> closed on vm1202
> 2011-07-15 14:01:30|20773|455:421|new|OS.pm:is_ssh_responding(416)|vm1202
> is NOT responding to SSH, ports 22 or 24 are both closed
> 2011-07-15
> 14:01:30|20773|455:421|new|Module.pm:code_loop_timeout(409)|attempt 2: code
> returned false, seconds elapsed/remaining: 16/284, sleeping for 15 seconds
> 2011-07-15 14:01:32|30621|vcld:main(166)|lastcheckin time updated for
> management node 1: 2011-07-15 14:01:32
> 2011-07-15
> 14:01:33|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
> remote IP is not defined
> 2011-07-15
> 14:01:33|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
> remote IP is not defined
> 2011-07-15 14:01:37|30621|vcld:main(166)|lastcheckin time updated for
> management node 1: 2011-07-15 14:01:37
> 2011-07-15
> 14:01:38|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
> remote IP is not defined
> 2011-07-15
> 14:01:38|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
> remote IP is not defined
> 2011-07-15 14:01:42|30621|vcld:main(166)|lastcheckin time updated for
> management node 1: 2011-07-15 14:01:42
> 2011-07-15
> 14:01:43|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
> remote IP is not defined
> 2011-07-15
> 14:01:43|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
> remote IP is not defined
> 2011-07-15
> 14:01:45|20773|455:421|new|Module.pm:code_loop_timeout(413)|attempt 3:
> waiting for vm1202 to respond to SSH
> 2011-07-15 14:01:45|20773|455:421|new|utils.pm:nmap_port(2707)|port 22 is
> closed on vm1202
> 2011-07-15 14:01:45|20773|455:421|new|utils.pm:nmap_port(2707)|port 24 is
> closed on vm1202
> 2011-07-15 14:01:45|20773|455:421|new|OS.pm:is_ssh_responding(416)|vm1202
> is NOT responding to SSH, ports 22 or 24 are both closed
> 2011-07-15
> 14:01:45|20773|455:421|new|Module.pm:code_loop_timeout(409)|attempt 3: code
> returned false, seconds elapsed/remaining: 31/269, sleeping for 15 seconds
> *Roger Herling*
> *Sr. Desktop Administrator*
> Marist College
> *Office:* 845-575-3347
> *Cell:* 845-240-4298
>
>
>
>
>
> From: Andy Kurth <an...@ncsu.edu>
> To: vcl-user@incubator.apache.org
> Date: 07/15/2011 01:44 PM
> Subject: Re: why does it take so long to provision a VM that
> already has the correct image on it?
> ------------------------------
>
>
>
> Hi Roger,
> Can you send the vcld.log output for a reservation that should have been
> preloaded but reloaded anyway.
>
> -Andy
>
> On Fri, Jul 15, 2011 at 12:20 PM, Roger Herling <*Roger.Herling@marist.edu
> * <Ro...@marist.edu>> wrote:
> To be more precise Vmware esx local and network storage
> *
> Roger Herling* *
> Sr. Desktop Administrator*
> Marist College *
> Office:* 845-575-3347 *
> Cell:* 845-240-4298
>
>
>
>
>
> From: Aaron Peeler <*fapeeler@ncsu.edu* <fa...@ncsu.edu>>
> To: *vcl-user@incubator.apache.org* <vc...@incubator.apache.org>
> Date: 07/15/2011 12:17 PM
> Subject: Re: why does it take so long to provision a VM that
> already has the correct image on it?
> ------------------------------
>
>
>
> Hello Roger,
>
> Which provisioning module are you using for your vms? In an older release,
> there was a *esx.pm* <http://esx.pm/> module which has this behavior.
>
> Make sure your not using that prov module.
> Aaron
>
> On Fri, Jul 15, 2011 at 11:59 AM, Roger Herling <*Roger.Herling@marist.edu
> * <Ro...@marist.edu>> wrote:
> Hi all we have been having an issue where all of our vm's are pre loaded
> with an image but when you request a reservation the VM is deleted and reset
> why is this happening. I thought that the whole purpose of having the vms
> ready to go was that provisioning time should only be 1-2 minutes instead it
> 5-7.
> *
>
> Roger Herling* *
> Sr. Desktop Administrator*
> Marist College *
> Office:* 845-575-3347 *
> Cell:* 845-240-4298
>
>
>
>
>
> --
> Aaron Peeler
> Program Manager
> Virtual Computing Lab
> NC State University
>
> All electronic mail messages in connection with State business which are
> sent to or received by this account are subject to the NC Public Records Law
> and may be disclosed to third parties.
>
>
Re: why does it take so long to provision a VM that already has the correct
image on it?
Posted by Roger Herling <Ro...@marist.edu>.
Sorry here is the full log
acknowledgement
2011-07-15
14:00:18|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15 14:00:21|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:00:21
2011-07-15
14:00:23|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:00:23|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15 14:00:27|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:00:26
2011-07-15
14:00:27|30621|455:421|new|utils.pm:reservation_being_processed(9010)|computerloadlog
'begin' entry does NOT exist for reservation 421
2011-07-15 14:00:27|30621|455:421|new|utils.pm:run_command(9082)|executed
command: pgrep -fl 'vcld [0-9]+:421 ', pid: 20758, exit status: 1, output:
2011-07-15
14:00:27|30621|455:421|new|utils.pm:is_management_node_process_running(9259)|process
is NOT running, identifier: 'vcld [0-9]+:421 '
2011-07-15
14:00:27|30621|455:421|new|utils.pm:reservation_being_processed(9031)|reservation
is NOT currently being processed
2011-07-15 14:00:27|30621|455:421|new|vcld:main(277)|reservation 421 is
NOT already being processed
2011-07-15
14:00:27|30621|455:421|new|utils.pm:get_request_info(4589)|standalone
affiliation found: Local
2011-07-15 14:00:27|30621|455:421|new|vcld:main(282)|retrieved request
information from database
2011-07-15
14:00:27|30621|455:421|new|DataStructure.pm:is_parent_reservation(943)|returning
true: parent reservation ID for this request: 421
2011-07-15
14:00:27|30621|455:421|new|utils.pm:update_request_state(2049)|request 455
state updated to: pending, laststate to: new
2011-07-15
14:00:27|30621|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, begin, beginning to process, state is new
2011-07-15 14:00:27|30621|455:421|new|vcld:make_new_child(510)|loaded
VCL::new module
2011-07-15 14:00:27|30621|455:421|new|vcld:make_new_child(567)|current
number of forked kids: 3
2011-07-15 14:00:27|20773|455:421|new|vcld:make_new_child(583)|vcld
environment variable set to 0 for this process
2011-07-15 14:00:27|20773|455:421|new|Module.pm:new(134)|constructor
called, class=VCL::new
2011-07-15 14:00:27|20773|455:421|new|Module.pm:new(156)|VCL::new object
created
2011-07-15 14:00:27|20773|455:421|new|State.pm:initialize(85)|obtained a
database handle for this state process, stored as $ENV{dbh}
2011-07-15 14:00:27|20773|455:421|new|State.pm:check_image_os(817)|no
corrections need to be made, not an imaging request, returning 1
2011-07-15
14:00:27|20773|455:421|new|DataStructure.pm:is_parent_reservation(943)|returning
true: parent reservation ID for this request: 421
2011-07-15
14:00:27|20773|455:421|new|utils.pm:rename_vcld_process(7183)|reservation
count: 1
2011-07-15
14:00:27|20773|455:421|new|utils.pm:rename_vcld_process(7202)|PARENTIMAGE:
1
2011-07-15
14:00:27|20773|455:421|new|utils.pm:rename_vcld_process(7203)|SUBIMAGE: 0
2011-07-15
14:00:27|20773|455:421|new|utils.pm:rename_vcld_process(7221)|renamed
process to 'vcld 455:421 new vm1202 vmwarewin7-MSProjectWin76474-v3 admin'
2011-07-15
14:00:27|20773|455:421|new|DataStructure.pm:is_parent_reservation(943)|returning
true: parent reservation ID for this request: 421
2011-07-15
14:00:27|20773|455:421|new|DataStructure.pm:is_parent_reservation(943)|returning
true: parent reservation ID for this request: 421
2011-07-15 14:00:27|20773|455:421|new|State.pm:initialize(118)|attempting
to load provisioning module: VCL::Module::Provisioning::VMware::VMware
2011-07-15
14:00:27|20773|455:421|new|State.pm:initialize(124)|VCL::Module::Provisioning::VMware::VMware
module loaded
2011-07-15 14:00:27|20773|455:421|new|Module.pm:new(134)|constructor
called, class=VCL::Module::Provisioning::VMware::VMware
2011-07-15
14:00:27|20773|455:421|new|Module.pm:new(156)|VCL::Module::Provisioning::VMware::VMware
object created
2011-07-15
14:00:27|20773|455:421|new|DataStructure.pm:_initialize(594)|computer ID
argument was specified, retrieving data for computer ID: 8
2011-07-15
14:00:27|20773|455:421|new|VMware.pm:get_vmhost_datastructure(923)|created
DataStructure object for VM host: blade12
2011-07-15
14:00:27|20773|455:421|new|DataStructure.pm:_initialize(594)|computer ID
argument was specified, retrieving data for computer ID: 8
2011-07-15
14:00:27|20773|455:421|new|VMware.pm:get_vmhost_datastructure(923)|created
DataStructure object for VM host: blade12
2011-07-15
14:00:27|20773|455:421|new|VMware.pm:get_vmhost_api_object(1027)|attempting
to load VMware control module:
VCL::Module::Provisioning::VMware::vSphere_SDK
2011-07-15
14:00:27|20773|455:421|new|VMware.pm:get_vmhost_api_object(1033)|loaded
VMware control module: VCL::Module::Provisioning::VMware::vSphere_SDK
2011-07-15 14:00:27|20773|455:421|new|Module.pm:new(134)|constructor
called, class=VCL::Module::Provisioning::VMware::vSphere_SDK
2011-07-15
14:00:27|20773|455:421|new|Module.pm:new(156)|VCL::Module::Provisioning::VMware::vSphere_SDK
object created
2011-07-15
14:00:27|20773|455:421|new|vSphere_SDK.pm:initialize(1816)|attempting to
connect to VM host: https://blade12/sdk
2011-07-15
14:00:27|20773|455:421|new|vSphere_SDK.pm:initialize(1826)|connected to VM
host: https://blade12/sdk
2011-07-15
14:00:27|20773|455:421|new|VMware.pm:get_vmhost_api_object(1046)|created
API object: VCL::Module::Provisioning::VMware::vSphere_SDK
2011-07-15
14:00:27|20773|455:421|new|vSphere_SDK.pm:is_restricted(1067)|access to
the VM host via the vSphere SDK is restricted due to the license:
RestrictedVersionFault
2011-07-15 14:00:27|20773|455:421|new|VMware.pm:initialize(240)|attempting
to create OS object for the image currently loaded on the VM host: blade12
|20773|455:421|new| image name: noimage
|20773|455:421|new| OS module: VCL::Module::OS::Linux::UnixLab
2011-07-15
14:00:27|20773|455:421|new|DataStructure.pm:_initialize(594)|computer ID
argument was specified, retrieving data for computer ID: 8
2011-07-15
14:00:27|20773|455:421|new|VMware.pm:get_vmhost_datastructure(923)|created
DataStructure object for VM host: blade12
2011-07-15
14:00:27|20773|455:421|new|VMware.pm:get_vmhost_os_object(965)|attempting
to load VM host OS module: VCL::Module::OS::Linux::UnixLab
2011-07-15
14:00:27|20773|455:421|new|VMware.pm:get_vmhost_os_object(971)|VM host OS
module loaded: VCL::Module::OS::Linux::UnixLab
2011-07-15 14:00:27|20773|455:421|new|Module.pm:new(134)|constructor
called, class=VCL::Module::OS::Linux::UnixLab
2011-07-15
14:00:27|20773|455:421|new|Module.pm:new(156)|VCL::Module::OS::Linux::UnixLab
object created
2011-07-15
14:00:27|20773|455:421|new|VMware.pm:get_vmhost_os_object(977)|VM host OS
object created: VCL::Module::OS::Linux::UnixLab
2011-07-15 14:00:27|20773|455:421|new|VMware.pm:initialize(241)|created OS
object to control the OS of VM host: blade12
2011-07-15 14:00:27|20773|455:421|new|utils.pm:nmap_port(2699)|port 22 is
open on blade12
2011-07-15 14:00:27|20773|455:421|new|utils.pm:nmap_port(2707)|port 24 is
closed on blade12
2011-07-15 14:00:27|20773|455:421|new|OS.pm:is_ssh_responding(430)|blade12
is responding to SSH, port 22: open, port 24: closed
2011-07-15 14:00:27|20773|455:421|new|VMware.pm:initialize(250)|OS of VM
host blade12 will be controlled via SSH using OS object:
VCL::Module::OS::Linux::UnixLab
2011-07-15
14:00:27|20773|455:421|new|DataStructure.pm:_initialize(594)|computer ID
argument was specified, retrieving data for computer ID: 8
2011-07-15
14:00:27|20773|455:421|new|VMware.pm:get_vmhost_datastructure(923)|created
DataStructure object for VM host: blade12
2011-07-15
14:00:27|20773|455:421|new|VMware.pm:get_vmhost_api_object(1027)|attempting
to load VMware control module: VCL::Module::Provisioning::VMware::VIM_SSH
2011-07-15
14:00:27|20773|455:421|new|VMware.pm:get_vmhost_api_object(1033)|loaded
VMware control module: VCL::Module::Provisioning::VMware::VIM_SSH
2011-07-15 14:00:27|20773|455:421|new|Module.pm:new(134)|constructor
called, class=VCL::Module::Provisioning::VMware::VIM_SSH
2011-07-15
14:00:27|20773|455:421|new|Module.pm:new(156)|VCL::Module::Provisioning::VMware::VIM_SSH
object created
2011-07-15 14:00:28|20773|455:421|new|VIM_SSH.pm:initialize(141)|VIM
executable available on VM host: vim-cmd
2011-07-15
14:00:28|20773|455:421|new|VIM_SSH.pm:initialize(143)|VCL::Module::Provisioning::VMware::VIM_SSH
object initialized
2011-07-15
14:00:28|20773|455:421|new|VMware.pm:get_vmhost_api_object(1046)|created
API object: VCL::Module::Provisioning::VMware::VIM_SSH
2011-07-15 14:00:28|20773|455:421|new|VMware.pm:initialize(264)|VIM SSH
command object will be used to control the VM: vm1202
2011-07-15
14:00:28|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:00:28|20495|453:419|reserved|reserved.pm:process(243)|attempt 10 of
180, user has not acknowleged
2011-07-15
14:00:28|20773|455:421|new|VMware.pm:get_vmhost_product_name(4090)|VMware
product being used on VM host blade12: 'VMware ESXi 4.1.0 build-260247'
2011-07-15
14:00:28|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15 14:00:28|20773|455:421|new|VMware.pm:initialize(294)|VMware
provisioning object initialized:
|20773|455:421|new| VM host OS object type:
VCL::Module::OS::Linux::UnixLab
|20773|455:421|new| API object type:
VCL::Module::Provisioning::VMware::VIM_SSH
2011-07-15
14:00:28|20773|455:421|new|State.pm:initialize(128)|VCL::Module::Provisioning::VMware::VMware
provisioner object created
2011-07-15 14:00:28|20773|455:421|new|State.pm:initialize(142)|attempting
to load OS module: VCL::Module::OS::Windows::Version_6::7
2011-07-15
14:00:28|20773|455:421|new|State.pm:initialize(148)|VCL::Module::OS::Windows::Version_6::7
module loaded
2011-07-15 14:00:28|20773|455:421|new|Module.pm:new(134)|constructor
called, class=VCL::Module::OS::Windows::Version_6::7
2011-07-15
14:00:28|20773|455:421|new|Module.pm:new(156)|VCL::Module::OS::Windows::Version_6::7
object created
2011-07-15
14:00:28|20773|455:421|new|State.pm:initialize(151)|VCL::Module::OS::Windows::Version_6::7
OS object created
2011-07-15 14:00:28|20773|455:421|new|State.pm:initialize(166)|returning 1
2011-07-15 14:00:28|20773|455:421|new|vcld:make_new_child(592)|VCL::new
object created and initialized
2011-07-15
14:00:28|20773|455:421|new|DataStructure.pm:is_parent_reservation(943)|returning
true: parent reservation ID for this request: 421
2011-07-15
14:00:28|20773|455:421|new|DataStructure.pm:get_computer_state_name(2227)|attempting
to retrieve current state of computer vm1202 from the database
2011-07-15
14:00:28|20773|455:421|new|DataStructure.pm:get_computer_state_name(2258)|retrieved
current state of computer vm1202 from the database: available
2011-07-15
14:00:28|20773|455:421|new|DataStructure.pm:_automethod(786)|data
structure updated:
$self->request_data->{reservation}{421}{computer}{state}{name}
|20773|455:421|new| computer_state_name = available
2011-07-15
14:00:28|20773|455:421|new|utils.pm:get_management_node_id(8740)|environment
variable: 1
2011-07-15 14:00:28|20773|455:421|new|new.pm:process(133)|reservation is
parent = 1
2011-07-15 14:00:28|20773|455:421|new|new.pm:process(134)|preload only = 0
2011-07-15 14:00:28|20773|455:421|new|new.pm:process(135)|originating
request state = new
2011-07-15 14:00:28|20773|455:421|new|new.pm:process(136)|originating
request laststate = new
2011-07-15 14:00:28|20773|455:421|new|new.pm:process(137)|originating
computer state = available
2011-07-15 14:00:28|20773|455:421|new|new.pm:process(138)|originating
computer type = virtualmachine
2011-07-15
14:00:28|20773|455:421|new|DataStructure.pm:is_parent_reservation(943)|returning
true: parent reservation ID for this request: 421
2011-07-15
14:00:28|20773|455:421|new|DataStructure.pm:get_computer_state_name(2227)|attempting
to retrieve current state of computer vm1202 from the database
2011-07-15
14:00:28|20773|455:421|new|DataStructure.pm:get_computer_state_name(2258)|retrieved
current state of computer vm1202 from the database: available
2011-07-15
14:00:28|20773|455:421|new|DataStructure.pm:_automethod(786)|data
structure updated:
$self->request_data->{reservation}{421}{computer}{state}{name}
|20773|455:421|new| computer_state_name = available
2011-07-15
14:00:28|20773|455:421|new|utils.pm:get_management_node_id(8740)|environment
variable: 1
2011-07-15
14:00:28|20773|455:421|new|new.pm:computer_not_being_used(787)|vm1202
state is available
2011-07-15
14:00:28|20773|455:421|new|new.pm:computer_not_being_used(797)|vm1202 is
available, its state is available
2011-07-15 14:00:28|20773|455:421|new|new.pm:process(186)|vm1202 is not
being used
2011-07-15
14:00:28|20773|455:421|new|DataStructure.pm:is_parent_reservation(943)|returning
true: parent reservation ID for this request: 421
2011-07-15
14:00:28|20773|455:421|new|DataStructure.pm:get_computer_state_name(2227)|attempting
to retrieve current state of computer vm1202 from the database
2011-07-15
14:00:28|20773|455:421|new|DataStructure.pm:get_computer_state_name(2258)|retrieved
current state of computer vm1202 from the database: available
2011-07-15
14:00:28|20773|455:421|new|DataStructure.pm:_automethod(786)|data
structure updated:
$self->request_data->{reservation}{421}{computer}{state}{name}
|20773|455:421|new| computer_state_name = available
2011-07-15
14:00:28|20773|455:421|new|utils.pm:get_management_node_id(8740)|environment
variable: 1
2011-07-15 14:00:28|20773|455:421|new|new.pm:reload_image(529)|calling
VCL::Module::Provisioning::VMware::VMware->node_status()
2011-07-15
14:00:29|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, statuscheck, checking status of node
2011-07-15 14:00:29|20773|455:421|new|utils.pm:nmap_port(2707)|port 22 is
closed on vm1202
2011-07-15 14:00:29|20773|455:421|new|utils.pm:nmap_port(2707)|port 24 is
closed on vm1202
2011-07-15 14:00:29|20773|455:421|new|OS.pm:is_ssh_responding(416)|vm1202
is NOT responding to SSH, ports 22 or 24 are both closed
2011-07-15 14:00:29|20773|455:421|new|VMware.pm:node_status(738)|VM vm1202
is not responding to SSH, returning 'RELOAD'
2011-07-15 14:00:29|20773|455:421|new|new.pm:reload_image(544)|node_status
returned a hash reference
2011-07-15 14:00:29|20773|455:421|new|new.pm:reload_image(549)|node_status
hash reference contains key {status}=RELOAD
2011-07-15 14:00:29|20773|455:421|new|new.pm:reload_image(624)|node status
is RELOAD, vm1202 will be reloaded
2011-07-15
14:00:29|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, loadimageblade, vm1202 must be reloaded with
vmwarewin7-MSProjectWin76474-v3
2011-07-15 14:00:29|20773|455:421|new|new.pm:reload_image(638)|calling
VCL::Module::Provisioning::VMware::VMware->does_image_exist()
2011-07-15
14:00:29|20773|455:421|new|VMware.pm:does_image_exist(2937)|image exists
in the non-persistent directory on the VM host:
/vmfs/volumes/nfs-datastore/vmwarewin7-MSProjectWin76474-v3/vmwarewin7-MSProjectWin76474-v3.vmdk
2011-07-15
14:00:29|20773|455:421|new|new.pm:reload_image(641)|vmwarewin7-MSProjectWin76474-v3
exists on this management node
2011-07-15
14:00:29|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, doesimageexists, confirmed image exists
2011-07-15
14:00:29|20773|455:421|new|utils.pm:update_computer_state(2091)|computer
13 state updated to: reloading
2011-07-15 14:00:29|20773|455:421|new|new.pm:reload_image(674)|computer
vm1202 state set to reloading
2011-07-15
14:00:29|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, info, computer state updated to reloading
2011-07-15 14:00:29|20773|455:421|new|new.pm:reload_image(685)|calling
VCL::Module::Provisioning::VMware::VMware->load() subroutine
2011-07-15
14:00:29|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, info, calling
VCL::Module::Provisioning::VMware::VMware->load() subroutine
2011-07-15
14:00:29|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, doesimageexists, image exists vmwarewin7-MSProjectWin76474-v3
2011-07-15
14:00:29|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, startload, vm1202 vmwarewin7-MSProjectWin76474-v3
2011-07-15
14:00:29|20773|455:421|new|VMware.pm:get_vmx_file_paths(3333)|attempting
to find existing vmx files on the VM host
2011-07-15 14:00:29|20773|455:421|new|Linux.pm:find_files(1933)|attempting
to find files on blade12, base directory path:
'/vmfs/volumes/local-datastore/', pattern: *.vmx, command: find
"/vmfs/volumes/local-datastore/" -type f -iname "*.vmx"
2011-07-15 14:00:30|20773|455:421|new|Linux.pm:find_files(1951)|matching
file count: 7
2011-07-15
14:00:31|20773|455:421|new|VMware.pm:get_vmx_file_paths(3344)|found 7
unique vmx files on VM host:
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1201_74-v3/vm1201_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1203_74-v3/vm1203_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1204_74-v3/vm1204_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1205_74-v3/vm1205_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1206_74-v3/vm1206_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1206_cs5fix/vm1206_cs5fix.vmx
2011-07-15
14:00:31|20773|455:421|new|VMware.pm:remove_existing_vms(1129)|ignoring
existing vmx directory: vm1201_74-v3
2011-07-15
14:00:31|20773|455:421|new|VMware.pm:remove_existing_vms(1114)|found
existing vmx directory with that appears to match vm1202:
/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15
14:00:31|20773|455:421|new|VMware.pm:get_vmx_info(3403)|attempting to
retrieve info from vmx file:
/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15
14:00:31|20773|455:421|new|Linux.pm:get_file_contents(1576)|retrieved 88
lines from file on blade12:
'/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx'
2011-07-15 14:00:31|20773|455:421|new|VMware.pm:delete_vm(3510)|attempting
to delete VM: /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15
14:00:31|20773|455:421|new|VMware.pm:get_vmx_info(3399)|returning
previously retrieved info from vmx file:
/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15 14:00:32|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:00:32
2011-07-15 14:00:32|20773|455:421|new|VMware.pm:is_vm_registered(2783)|VM
is registered: /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15
14:00:33|20773|455:421|new|VIM_SSH.pm:get_vm_power_state(954)|VM is
powered on: /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15
14:00:33|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:00:33|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15 14:00:37|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:00:37
2011-07-15
14:00:38|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:00:38|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:00:40|20773|455:421|new|VIM_SSH.pm:_wait_for_task(830)|checking status
of task: haTask-3456-vim.VirtualMachine.powerOff-20732
2011-07-15 14:00:40|20773|455:421|new|VIM_SSH.pm:_wait_for_task(843)|task
completed successfully: haTask-3456-vim.VirtualMachine.powerOff-20732
2011-07-15
14:00:40|20773|455:421|new|VIM_SSH.pm:vm_power_off(1112)|powered off VM:
/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15 14:00:42|20773|455:421|new|VMware.pm:is_vm_registered(2788)|VM
is not registered:
'/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx', registered
paths:
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1206_74-v3/vm1206_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1203_74-v3/vm1203_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1204_74-v3/vm1204_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1205_74-v3/vm1205_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1201_74-v3/vm1201_74-v3.vmx
2011-07-15
14:00:42|20773|455:421|new|VIM_SSH.pm:vm_unregister(1244)|unregistered VM:
/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx (ID: 3456)
2011-07-15 14:00:42|20773|455:421|new|VMware.pm:delete_vm(3533)|checking
if existing VM's vmdk file should be deleted:
|20773|455:421|new| vmdk file path:
/vmfs/volumes/nfs-datastore/vmwarewin7-MSProjectWin76474-v3/vmwarewin7-MSProjectWin76474-v3.vmdk
|20773|455:421|new| vmx storage identier key: scsi0:0
|20773|455:421|new| disk mode: independent-nonpersistent
2011-07-15 14:00:42|20773|455:421|new|VMware.pm:delete_vm(3543)|mode of
vmdk file: independent-nonpersistent, vmdk directory will NOT be deleted
2011-07-15 14:00:42|20773|455:421|new|VMware.pm:delete_vm(3556)|attempt
1/5: attempting to delete vmx directory:
/vmfs/volumes/local-datastore/vm1202_74-v3
2011-07-15 14:00:42|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:00:42
2011-07-15 14:00:42|20773|455:421|new|Linux.pm:delete_file(1410)|deleted
'/vmfs/volumes/local-datastore/vm1202_74-v3' on blade12
2011-07-15 14:00:43|20773|455:421|new|Linux.pm:file_exists(1341)|file or
directory does not exist on blade12:
'/vmfs/volumes/local-datastore/vm1202_74-v3'
2011-07-15 14:00:43|20773|455:421|new|Linux.pm:delete_file(1424)|confirmed
file does not exist on blade12:
'/vmfs/volumes/local-datastore/vm1202_74-v3'
2011-07-15 14:00:43|20773|455:421|new|VMware.pm:delete_vm(3558)|deleted
VM: /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15
14:00:43|20773|455:421|new|VMware.pm:remove_existing_vms(1129)|ignoring
existing vmx directory: vm1203_74-v3
2011-07-15
14:00:43|20773|455:421|new|VMware.pm:remove_existing_vms(1129)|ignoring
existing vmx directory: vm1204_74-v3
2011-07-15
14:00:43|20773|455:421|new|VMware.pm:remove_existing_vms(1129)|ignoring
existing vmx directory: vm1205_74-v3
2011-07-15
14:00:43|20773|455:421|new|VMware.pm:remove_existing_vms(1129)|ignoring
existing vmx directory: vm1206_74-v3
2011-07-15
14:00:43|20773|455:421|new|VMware.pm:remove_existing_vms(1129)|ignoring
existing vmx directory: vm1206_cs5fix
2011-07-15
14:00:43|20773|455:421|new|VMware.pm:get_repository_vmdk_base_directory_path(2655)|repository
path is not set for the VM profile, using management node install path:
/install/vmware_images
2011-07-15
14:00:43|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:00:43|20773|455:421|new|VMware.pm:get_vmhost_product_name(4090)|VMware
product being used on VM host blade12: 'VMware ESXi 4.1.0 build-260247'
2011-07-15
14:00:43|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:00:44|20773|455:421|new|VIM_SSH.pm:_get_datastore_names(477)|retrieved
datastore names: local-datastore, nfs-datastore
2011-07-15
14:00:45|20773|455:421|new|VIM_SSH.pm:get_virtual_disk_type(1370)|vmwarewin7-MSProjectWin76474-v3.vmdk
disk type: FlatVer2
2011-07-15
14:00:45|20773|455:421|new|VMware.pm:check_vmdk_disk_type(1657)|flat
virtual disk (FlatVer2) does not need to be converted for VMware ESXi
4.1.0 build-260247
2011-07-15
14:00:45|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, transfervm, copied vmwarewin7-MSProjectWin76474-v3 to vm1202
2011-07-15
14:00:45|20773|455:421|new|VMware.pm:get_vm_os_configuration(3212)|retrieved
default VM configuration for OS: 7-x86
|20773|455:421|new| : {
|20773|455:421|new| : "ethernet-virtualDev" => "e1000",
|20773|455:421|new| : "guestOS" => "winvista",
|20773|455:421|new| : "scsi-virtualDev" => "lsiLogic"
|20773|455:421|new| : }
2011-07-15 14:00:47|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:00:47
2011-07-15
14:00:47|20773|455:421|new|VIM_SSH.pm:get_virtual_disk_controller_type(1521)|retrieved
controller type for vmwarewin7-MSProjectWin76474-v3.vmdk: 'LsiLogic'
2011-07-15
14:00:47|20773|455:421|new|VMware.pm:get_vm_disk_adapter_type(3073)|retrieved
VM disk adapter type from api object: LsiLogic
2011-07-15
14:00:48|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:00:48|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:00:49|20773|455:421|new|VIM_SSH.pm:get_virtual_disk_hardware_version(1669)|retrieved
hardware version for vmwarewin7-MSProjectWin76474-v3.vmdk: '7'
2011-07-15
14:00:49|20773|455:421|new|VMware.pm:get_vm_virtual_hardware_version(3120)|retrieved
hardware version from api object: 7
2011-07-15
14:00:49|20773|455:421|new|VMware.pm:get_vm_virtual_hardware_version(3158)|returning
hardware version: 7
2011-07-15
14:00:49|20773|455:421|new|Linux.pm:create_directory(1475)|directory
either created or already exists on blade12:
'/vmfs/volumes/local-datastore/vm1202_74-v3'
2011-07-15 14:00:49|20773|455:421|new|VMware.pm:prepare_vmx(1222)|vm info:
|20773|455:421|new| display name: vm1202:vmwarewin7-MSProjectWin76474-v3
(nonpersistent)
|20773|455:421|new| image ID: 74
|20773|455:421|new| imagerevision ID: 81
|20773|455:421|new| vmx path:
/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
|20773|455:421|new| vmx directory name: vm1202_74-v3
|20773|455:421|new| vmx directory path:
/vmfs/volumes/local-datastore/vm1202_74-v3
|20773|455:421|new| vmdk file path:
/vmfs/volumes/nfs-datastore/vmwarewin7-MSProjectWin76474-v3/vmwarewin7-MSProjectWin76474-v3.vmdk
|20773|455:421|new| persistent: 0
|20773|455:421|new| computer ID: 13
|20773|455:421|new| computer name: vm1202
|20773|455:421|new| image name: vmwarewin7-MSProjectWin76474-v3
|20773|455:421|new| guest OS: winvista
|20773|455:421|new| virtual hardware version: 7
|20773|455:421|new| RAM: 4096
|20773|455:421|new| CPU count: 2
|20773|455:421|new| ethernet adapter type: e1000
|20773|455:421|new| virtual switch 0: Private
|20773|455:421|new| eth0 MAC address: 00:50:56:12:02:01
|20773|455:421|new| virtual switch 1: Public
|20773|455:421|new| eth1 MAC address: 00:50:56:12:02:02
|20773|455:421|new| disk adapter type: LsiLogic
|20773|455:421|new| disk mode: independent-nonpersistent
|20773|455:421|new| disk write through: FALSE
2011-07-15 14:00:49|20773|455:421|new|VMware.pm:prepare_vmx(1386)|image
project is: vcl, additional network adapters will not be configured
2011-07-15 14:00:49|20773|455:421|new|VMware.pm:prepare_vmx(1389)|vmx
parameters:
|20773|455:421|new| : {
|20773|455:421|new| : "#computer_id" => 13,
|20773|455:421|new| : "#image_id" => 74,
|20773|455:421|new| : "#imagerevision_id" => 81,
|20773|455:421|new| : ".encoding" => "UTF-8",
|20773|455:421|new| : "config.version" => 8,
|20773|455:421|new| : "disk.locking" => "false",
|20773|455:421|new| : "displayName" =>
"vm1202:vmwarewin7-MSProjectWin76474-v3 (nonpersistent)",
|20773|455:421|new| : "ethernet0.address" => "00:50:56:12:02:01",
|20773|455:421|new| : "ethernet0.addressType" => "static",
|20773|455:421|new| : "ethernet0.networkName" => "Private",
|20773|455:421|new| : "ethernet0.present" => "TRUE",
|20773|455:421|new| : "ethernet0.virtualDev" => "e1000",
|20773|455:421|new| : "ethernet1.address" => "00:50:56:12:02:02",
|20773|455:421|new| : "ethernet1.addressType" => "static",
|20773|455:421|new| : "ethernet1.networkName" => "Public",
|20773|455:421|new| : "ethernet1.present" => "TRUE",
|20773|455:421|new| : "ethernet1.virtualDev" => "e1000",
|20773|455:421|new| : "floppy0.present" => "FALSE",
|20773|455:421|new| : "guestOS" => "winvista",
|20773|455:421|new| : "gui.exitOnCLIHLT" => "TRUE",
|20773|455:421|new| : "memsize" => 4096,
|20773|455:421|new| : "msg.autoAnswer" => "TRUE",
|20773|455:421|new| : "numvcpus" => 2,
|20773|455:421|new| : "pciBridge0.present" => "TRUE",
|20773|455:421|new| : "pciBridge4.functions" => 8,
|20773|455:421|new| : "pciBridge4.present" => "TRUE",
|20773|455:421|new| : "pciBridge4.virtualDev" => "pcieRootPort",
|20773|455:421|new| : "pciBridge5.functions" => 8,
|20773|455:421|new| : "pciBridge5.present" => "TRUE",
|20773|455:421|new| : "pciBridge5.virtualDev" => "pcieRootPort",
|20773|455:421|new| : "pciBridge6.functions" => 8,
|20773|455:421|new| : "pciBridge6.present" => "TRUE",
|20773|455:421|new| : "pciBridge6.virtualDev" => "pcieRootPort",
|20773|455:421|new| : "pciBridge7.functions" => 8,
|20773|455:421|new| : "pciBridge7.present" => "TRUE",
|20773|455:421|new| : "pciBridge7.virtualDev" => "pcieRootPort",
|20773|455:421|new| : "powerType.powerOff" => "soft",
|20773|455:421|new| : "powerType.powerOn" => "hard",
|20773|455:421|new| : "powerType.reset" => "soft",
|20773|455:421|new| : "powerType.suspend" => "hard",
|20773|455:421|new| : "scsi0.present" => "TRUE",
|20773|455:421|new| : "scsi0.virtualDev" => "LsiLogic",
|20773|455:421|new| : "scsi0:0.fileName" =>
"/vmfs/volumes/nfs-datastore/vmwarewin7-MSProjectWin76474-v3/vmwarewin7-MSProjectWin76474-v3.vmdk",
|20773|455:421|new| : "scsi0:0.mode" => "independent-nonpersistent",
|20773|455:421|new| : "scsi0:0.present" => "TRUE",
|20773|455:421|new| : "scsi0:0.writeThrough" => "FALSE",
|20773|455:421|new| : "snapshot.disabled" => "TRUE",
|20773|455:421|new| : "svga.vramSize" => 33554432,
|20773|455:421|new| : "toolScripts.afterPowerOn" => "TRUE",
|20773|455:421|new| : "toolScripts.afterResume" => "TRUE",
|20773|455:421|new| : "toolScripts.beforePowerOff" => "TRUE",
|20773|455:421|new| : "toolScripts.beforeSuspend" => "TRUE",
|20773|455:421|new| : "tools.remindInstall" => "TRUE",
|20773|455:421|new| : "tools.syncTime" => "FALSE",
|20773|455:421|new| : "uuid.action" => "keep",
|20773|455:421|new| : "virtualHW.version" => 7,
|20773|455:421|new| : "vmci0.present" => "TRUE"
|20773|455:421|new| : }
2011-07-15 14:00:49|20773|455:421|new|VMware.pm:prepare_vmx(1400)|created
temporary vmx file: /tmp/vm1202_74-v3.vmx
2011-07-15
14:00:49|20773|455:421|new|Linux.pm:create_directory(1475)|directory
either created or already exists on blade12:
'/vmfs/volumes/local-datastore/vm1202_74-v3'
2011-07-15
14:00:49|20773|455:421|new|utils.pm:run_scp_command(5671)|attempt 1/3:
executing SCP command: /usr/bin/scp -B -i /etc/vcl/vcl.key -P 22 -p -r
/tmp/vm1202_74-v3.vmx
blade12:"/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx" 2>&1
2011-07-15 14:00:50|20773|455:421|new|utils.pm:run_scp_command(5722)|scp
successful: attempt 1/3, exit status: 0, output:
2011-07-15 14:00:50|20773|455:421|new|Linux.pm:copy_file_to(1740)|copied
file from management node to blade12: '/tmp/vm1202_74-v3.vmx' -->
blade12:'/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx'
2011-07-15 14:00:50|20773|455:421|new|VMware.pm:prepare_vmx(1409)|created
vmx file on VM host:
/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15 14:00:50|20773|455:421|new|VMware.pm:prepare_vmx(1412)|deleted
temporary vmx file: /tmp/vm1202_74-v3.vmx
2011-07-15
14:00:50|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, vmsetupconfig, prepared vmx file
2011-07-15 14:00:50|20773|455:421|new|VMware.pm:is_vm_registered(2788)|VM
is not registered:
'/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx', registered
paths:
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1206_74-v3/vm1206_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1203_74-v3/vm1203_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1204_74-v3/vm1204_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1205_74-v3/vm1205_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1201_74-v3/vm1201_74-v3.vmx
2011-07-15 14:00:52|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:00:52
2011-07-15 14:00:53|20773|455:421|new|VMware.pm:is_vm_registered(2783)|VM
is registered: /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15
14:00:53|20773|455:421|new|VIM_SSH.pm:vm_register(1172)|registered VM:
'/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx'
2011-07-15
14:00:53|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:00:53|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15 14:00:57|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:00:57
2011-07-15
14:00:58|20773|455:421|new|VIM_SSH.pm:_wait_for_task(830)|checking status
of task: haTask-3792-vim.VirtualMachine.powerOn-20780
2011-07-15
14:00:58|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:00:58|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15 14:00:58|20773|455:421|new|VIM_SSH.pm:_wait_for_task(843)|task
completed successfully: haTask-3792-vim.VirtualMachine.powerOn-20780
2011-07-15 14:00:58|20773|455:421|new|VIM_SSH.pm:vm_power_on(1037)|powered
on VM: /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15
14:00:58|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, startvm, registered and powered on vm1202
2011-07-15
14:00:58|20773|455:421|new|Version_6.pm:post_load(185)|beginning Windows
version 6 post-load tasks
2011-07-15 14:00:58|20773|455:421|new|Version_6.pm:post_load(193)|calling
parent class post_load() subroutine
2011-07-15 14:00:58|20773|455:421|new|Windows.pm:post_load(550)|beginning
Windows post-load tasks on vm1202
2011-07-15 14:00:59|20773|455:421|new|utils.pm:nmap_port(2707)|port 22 is
closed on vm1202
2011-07-15 14:00:59|20773|455:421|new|utils.pm:nmap_port(2707)|port 24 is
closed on vm1202
2011-07-15 14:00:59|20773|455:421|new|OS.pm:is_ssh_responding(416)|vm1202
is NOT responding to SSH, ports 22 or 24 are both closed
2011-07-15 14:00:59|20773|455:421|new|OS.pm:wait_for_response(477)|waiting
15 seconds for vm1202 to boot
2011-07-15 14:01:02|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:01:02
2011-07-15
14:01:03|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:03|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:03|20723|454:420|reserved|reserved.pm:process(243)|attempt 10 of
180, user has not acknowleged
2011-07-15 14:01:07|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:01:07
2011-07-15
14:01:08|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:08|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15 14:01:12|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:01:12
2011-07-15
14:01:13|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:13|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15 14:01:14|20773|455:421|new|OS.pm:wait_for_response(479)|waited
15 seconds for vm1202 to boot
2011-07-15 14:01:14|20773|455:421|new|OS.pm:wait_for_response(483)|waiting
for vm1202 to respond to SSH, maximum of 300 seconds
2011-07-15
14:01:14|20773|455:421|new|Module.pm:code_loop_timeout(396)|waiting for
vm1202 to respond to SSH, maximum of 300 seconds
2011-07-15
14:01:14|20773|455:421|new|Module.pm:code_loop_timeout(413)|attempt 1:
waiting for vm1202 to respond to SSH
2011-07-15 14:01:14|20773|455:421|new|utils.pm:nmap_port(2707)|port 22 is
closed on vm1202
2011-07-15 14:01:14|20773|455:421|new|utils.pm:nmap_port(2707)|port 24 is
closed on vm1202
2011-07-15 14:01:14|20773|455:421|new|OS.pm:is_ssh_responding(416)|vm1202
is NOT responding to SSH, ports 22 or 24 are both closed
2011-07-15
14:01:14|20773|455:421|new|Module.pm:code_loop_timeout(409)|attempt 1:
code returned false, seconds elapsed/remaining: 0/300, sleeping for 15
seconds
2011-07-15 14:01:17|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:01:17
2011-07-15
14:01:18|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:18|20495|453:419|reserved|reserved.pm:process(243)|attempt 20 of
180, user has not acknowleged
2011-07-15
14:01:18|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15 14:01:22|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:01:22
2011-07-15
14:01:23|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:23|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15 14:01:27|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:01:27
2011-07-15
14:01:28|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:28|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:29|20773|455:421|new|Module.pm:code_loop_timeout(413)|attempt 2:
waiting for vm1202 to respond to SSH
2011-07-15 14:01:30|20773|455:421|new|utils.pm:nmap_port(2707)|port 22 is
closed on vm1202
2011-07-15 14:01:30|20773|455:421|new|utils.pm:nmap_port(2707)|port 24 is
closed on vm1202
2011-07-15 14:01:30|20773|455:421|new|OS.pm:is_ssh_responding(416)|vm1202
is NOT responding to SSH, ports 22 or 24 are both closed
2011-07-15
14:01:30|20773|455:421|new|Module.pm:code_loop_timeout(409)|attempt 2:
code returned false, seconds elapsed/remaining: 16/284, sleeping for 15
seconds
2011-07-15 14:01:32|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:01:32
2011-07-15
14:01:33|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:33|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15 14:01:37|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:01:37
2011-07-15
14:01:38|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:38|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15 14:01:42|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:01:42
2011-07-15
14:01:43|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:43|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:45|20773|455:421|new|Module.pm:code_loop_timeout(413)|attempt 3:
waiting for vm1202 to respond to SSH
2011-07-15 14:01:45|20773|455:421|new|utils.pm:nmap_port(2707)|port 22 is
closed on vm1202
2011-07-15 14:01:45|20773|455:421|new|utils.pm:nmap_port(2707)|port 24 is
closed on vm1202
2011-07-15 14:01:45|20773|455:421|new|OS.pm:is_ssh_responding(416)|vm1202
is NOT responding to SSH, ports 22 or 24 are both closed
2011-07-15
14:01:45|20773|455:421|new|Module.pm:code_loop_timeout(409)|attempt 3:
code returned false, seconds elapsed/remaining: 31/269, sleeping for 15
seconds
Roger Herling
Sr. Desktop Administrator
Marist College
Office: 845-575-3347
Cell: 845-240-4298
From: Roger Herling <Ro...@marist.edu>
To: vcl-user@incubator.apache.org
Date: 07/15/2011 02:05 PM
Subject: Re: why does it take so long to provision a VM that
already has the correct image on it?
Hey Andy here you go. I was able to get two Vms to provision within
45seconds but those where two that had just been reloaded 10 minutes
earlier. It appears to only happen when a machine is idle for a while.
{421}{computer}{state}{name}
|20773|455:421|new| computer_state_name = available
2011-07-15
14:00:28|20773|455:421|new|utils.pm:get_management_node_id(8740)|environment
variable: 1
2011-07-15 14:00:28|20773|455:421|new|new.pm:process(133)|reservation is
parent = 1
2011-07-15 14:00:28|20773|455:421|new|new.pm:process(134)|preload only = 0
2011-07-15 14:00:28|20773|455:421|new|new.pm:process(135)|originating
request state = new
2011-07-15 14:00:28|20773|455:421|new|new.pm:process(136)|originating
request laststate = new
2011-07-15 14:00:28|20773|455:421|new|new.pm:process(137)|originating
computer state = available
2011-07-15 14:00:28|20773|455:421|new|new.pm:process(138)|originating
computer type = virtualmachine
2011-07-15
14:00:28|20773|455:421|new|DataStructure.pm:is_parent_reservation(943)|returning
true: parent reservation ID for this request: 421
2011-07-15
14:00:28|20773|455:421|new|DataStructure.pm:get_computer_state_name(2227)|attempting
to retrieve current state of computer vm1202 from the database
2011-07-15
14:00:28|20773|455:421|new|DataStructure.pm:get_computer_state_name(2258)|retrieved
current state of computer vm1202 from the database: available
2011-07-15
14:00:28|20773|455:421|new|DataStructure.pm:_automethod(786)|data
structure updated:
$self->request_data->{reservation}{421}{computer}{state}{name}
|20773|455:421|new| computer_state_name = available
2011-07-15
14:00:28|20773|455:421|new|utils.pm:get_management_node_id(8740)|environment
variable: 1
2011-07-15
14:00:28|20773|455:421|new|new.pm:computer_not_being_used(787)|vm1202
state is available
2011-07-15
14:00:28|20773|455:421|new|new.pm:computer_not_being_used(797)|vm1202 is
available, its state is available
2011-07-15 14:00:28|20773|455:421|new|new.pm:process(186)|vm1202 is not
being used
2011-07-15
14:00:28|20773|455:421|new|DataStructure.pm:is_parent_reservation(943)|returning
true: parent reservation ID for this request: 421
2011-07-15
14:00:28|20773|455:421|new|DataStructure.pm:get_computer_state_name(2227)|attempting
to retrieve current state of computer vm1202 from the database
2011-07-15
14:00:28|20773|455:421|new|DataStructure.pm:get_computer_state_name(2258)|retrieved
current state of computer vm1202 from the database: available
2011-07-15
14:00:28|20773|455:421|new|DataStructure.pm:_automethod(786)|data
structure updated:
$self->request_data->{reservation}{421}{computer}{state}{name}
|20773|455:421|new| computer_state_name = available
2011-07-15
14:00:28|20773|455:421|new|utils.pm:get_management_node_id(8740)|environment
variable: 1
2011-07-15 14:00:28|20773|455:421|new|new.pm:reload_image(529)|calling
VCL::Module::Provisioning::VMware::VMware->node_status()
2011-07-15
14:00:29|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, statuscheck, checking status of node
2011-07-15 14:00:29|20773|455:421|new|utils.pm:nmap_port(2707)|port 22 is
closed on vm1202
2011-07-15 14:00:29|20773|455:421|new|utils.pm:nmap_port(2707)|port 24 is
closed on vm1202
2011-07-15 14:00:29|20773|455:421|new|OS.pm:is_ssh_responding(416)|vm1202
is NOT responding to SSH, ports 22 or 24 are both closed
2011-07-15 14:00:29|20773|455:421|new|VMware.pm:node_status(738)|VM vm1202
is not responding to SSH, returning 'RELOAD'
2011-07-15 14:00:29|20773|455:421|new|new.pm:reload_image(544)|node_status
returned a hash reference
2011-07-15 14:00:29|20773|455:421|new|new.pm:reload_image(549)|node_status
hash reference contains key {status}=RELOAD
2011-07-15 14:00:29|20773|455:421|new|new.pm:reload_image(624)|node status
is RELOAD, vm1202 will be reloaded
2011-07-15
14:00:29|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, loadimageblade, vm1202 must be reloaded with
vmwarewin7-MSProjectWin76474-v3
2011-07-15 14:00:29|20773|455:421|new|new.pm:reload_image(638)|calling
VCL::Module::Provisioning::VMware::VMware->does_image_exist()
2011-07-15
14:00:29|20773|455:421|new|VMware.pm:does_image_exist(2937)|image exists
in the non-persistent directory on the VM host:
/vmfs/volumes/nfs-datastore/vmwarewin7-MSProjectWin76474-v3/vmwarewin7-MSProjectWin76474-v3.vmdk
2011-07-15
14:00:29|20773|455:421|new|new.pm:reload_image(641)|vmwarewin7-MSProjectWin76474-v3
exists on this management node
2011-07-15
14:00:29|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, doesimageexists, confirmed image exists
2011-07-15
14:00:29|20773|455:421|new|utils.pm:update_computer_state(2091)|computer
13 state updated to: reloading
2011-07-15 14:00:29|20773|455:421|new|new.pm:reload_image(674)|computer
vm1202 state set to reloading
2011-07-15
14:00:29|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, info, computer state updated to reloading
2011-07-15 14:00:29|20773|455:421|new|new.pm:reload_image(685)|calling
VCL::Module::Provisioning::VMware::VMware->load() subroutine
2011-07-15
14:00:29|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, info, calling
VCL::Module::Provisioning::VMware::VMware->load() subroutine
2011-07-15
14:00:29|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, doesimageexists, image exists vmwarewin7-MSProjectWin76474-v3
2011-07-15
14:00:29|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, startload, vm1202 vmwarewin7-MSProjectWin76474-v3
2011-07-15
14:00:29|20773|455:421|new|VMware.pm:get_vmx_file_paths(3333)|attempting
to find existing vmx files on the VM host
2011-07-15 14:00:29|20773|455:421|new|Linux.pm:find_files(1933)|attempting
to find files on blade12, base directory path:
'/vmfs/volumes/local-datastore/', pattern: *.vmx, command: find
"/vmfs/volumes/local-datastore/" -type f -iname "*.vmx"
2011-07-15 14:00:30|20773|455:421|new|Linux.pm:find_files(1951)|matching
file count: 7
2011-07-15
14:00:31|20773|455:421|new|VMware.pm:get_vmx_file_paths(3344)|found 7
unique vmx files on VM host:
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1201_74-v3/vm1201_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1203_74-v3/vm1203_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1204_74-v3/vm1204_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1205_74-v3/vm1205_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1206_74-v3/vm1206_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1206_cs5fix/vm1206_cs5fix.vmx
2011-07-15
14:00:31|20773|455:421|new|VMware.pm:remove_existing_vms(1129)|ignoring
existing vmx directory: vm1201_74-v3
2011-07-15
14:00:31|20773|455:421|new|VMware.pm:remove_existing_vms(1114)|found
existing vmx directory with that appears to match vm1202:
/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15
14:00:31|20773|455:421|new|VMware.pm:get_vmx_info(3403)|attempting to
retrieve info from vmx file:
/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15
14:00:31|20773|455:421|new|Linux.pm:get_file_contents(1576)|retrieved 88
lines from file on blade12:
'/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx'
2011-07-15 14:00:31|20773|455:421|new|VMware.pm:delete_vm(3510)|attempting
to delete VM: /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15
14:00:31|20773|455:421|new|VMware.pm:get_vmx_info(3399)|returning
previously retrieved info from vmx file:
/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15 14:00:32|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:00:32
2011-07-15 14:00:32|20773|455:421|new|VMware.pm:is_vm_registered(2783)|VM
is registered: /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15
14:00:33|20773|455:421|new|VIM_SSH.pm:get_vm_power_state(954)|VM is
powered on: /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15
14:00:33|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:00:33|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15 14:00:37|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:00:37
2011-07-15
14:00:38|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:00:38|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:00:40|20773|455:421|new|VIM_SSH.pm:_wait_for_task(830)|checking status
of task: haTask-3456-vim.VirtualMachine.powerOff-20732
2011-07-15 14:00:40|20773|455:421|new|VIM_SSH.pm:_wait_for_task(843)|task
completed successfully: haTask-3456-vim.VirtualMachine.powerOff-20732
2011-07-15
14:00:40|20773|455:421|new|VIM_SSH.pm:vm_power_off(1112)|powered off VM:
/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15 14:00:42|20773|455:421|new|VMware.pm:is_vm_registered(2788)|VM
is not registered:
'/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx', registered
paths:
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1206_74-v3/vm1206_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1203_74-v3/vm1203_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1204_74-v3/vm1204_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1205_74-v3/vm1205_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1201_74-v3/vm1201_74-v3.vmx
2011-07-15
14:00:42|20773|455:421|new|VIM_SSH.pm:vm_unregister(1244)|unregistered VM:
/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx (ID: 3456)
2011-07-15 14:00:42|20773|455:421|new|VMware.pm:delete_vm(3533)|checking
if existing VM's vmdk file should be deleted:
|20773|455:421|new| vmdk file path:
/vmfs/volumes/nfs-datastore/vmwarewin7-MSProjectWin76474-v3/vmwarewin7-MSProjectWin76474-v3.vmdk
|20773|455:421|new| vmx storage identier key: scsi0:0
|20773|455:421|new| disk mode: independent-nonpersistent
2011-07-15 14:00:42|20773|455:421|new|VMware.pm:delete_vm(3543)|mode of
vmdk file: independent-nonpersistent, vmdk directory will NOT be deleted
2011-07-15 14:00:42|20773|455:421|new|VMware.pm:delete_vm(3556)|attempt
1/5: attempting to delete vmx directory:
/vmfs/volumes/local-datastore/vm1202_74-v3
2011-07-15 14:00:42|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:00:42
2011-07-15 14:00:42|20773|455:421|new|Linux.pm:delete_file(1410)|deleted
'/vmfs/volumes/local-datastore/vm1202_74-v3' on blade12
2011-07-15 14:00:43|20773|455:421|new|Linux.pm:file_exists(1341)|file or
directory does not exist on blade12:
'/vmfs/volumes/local-datastore/vm1202_74-v3'
2011-07-15 14:00:43|20773|455:421|new|Linux.pm:delete_file(1424)|confirmed
file does not exist on blade12:
'/vmfs/volumes/local-datastore/vm1202_74-v3'
2011-07-15 14:00:43|20773|455:421|new|VMware.pm:delete_vm(3558)|deleted
VM: /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15
14:00:43|20773|455:421|new|VMware.pm:remove_existing_vms(1129)|ignoring
existing vmx directory: vm1203_74-v3
2011-07-15
14:00:43|20773|455:421|new|VMware.pm:remove_existing_vms(1129)|ignoring
existing vmx directory: vm1204_74-v3
2011-07-15
14:00:43|20773|455:421|new|VMware.pm:remove_existing_vms(1129)|ignoring
existing vmx directory: vm1205_74-v3
2011-07-15
14:00:43|20773|455:421|new|VMware.pm:remove_existing_vms(1129)|ignoring
existing vmx directory: vm1206_74-v3
2011-07-15
14:00:43|20773|455:421|new|VMware.pm:remove_existing_vms(1129)|ignoring
existing vmx directory: vm1206_cs5fix
2011-07-15
14:00:43|20773|455:421|new|VMware.pm:get_repository_vmdk_base_directory_path(2655)|repository
path is not set for the VM profile, using management node install path:
/install/vmware_images
2011-07-15
14:00:43|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:00:43|20773|455:421|new|VMware.pm:get_vmhost_product_name(4090)|VMware
product being used on VM host blade12: 'VMware ESXi 4.1.0 build-260247'
2011-07-15
14:00:43|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:00:44|20773|455:421|new|VIM_SSH.pm:_get_datastore_names(477)|retrieved
datastore names: local-datastore, nfs-datastore
2011-07-15
14:00:45|20773|455:421|new|VIM_SSH.pm:get_virtual_disk_type(1370)|vmwarewin7-MSProjectWin76474-v3.vmdk
disk type: FlatVer2
2011-07-15
14:00:45|20773|455:421|new|VMware.pm:check_vmdk_disk_type(1657)|flat
virtual disk (FlatVer2) does not need to be converted for VMware ESXi
4.1.0 build-260247
2011-07-15
14:00:45|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, transfervm, copied vmwarewin7-MSProjectWin76474-v3 to vm1202
2011-07-15
14:00:45|20773|455:421|new|VMware.pm:get_vm_os_configuration(3212)|retrieved
default VM configuration for OS: 7-x86
|20773|455:421|new| : {
|20773|455:421|new| : "ethernet-virtualDev" => "e1000",
|20773|455:421|new| : "guestOS" => "winvista",
|20773|455:421|new| : "scsi-virtualDev" => "lsiLogic"
|20773|455:421|new| : }
2011-07-15 14:00:47|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:00:47
2011-07-15
14:00:47|20773|455:421|new|VIM_SSH.pm:get_virtual_disk_controller_type(1521)|retrieved
controller type for vmwarewin7-MSProjectWin76474-v3.vmdk: 'LsiLogic'
2011-07-15
14:00:47|20773|455:421|new|VMware.pm:get_vm_disk_adapter_type(3073)|retrieved
VM disk adapter type from api object: LsiLogic
2011-07-15
14:00:48|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:00:48|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:00:49|20773|455:421|new|VIM_SSH.pm:get_virtual_disk_hardware_version(1669)|retrieved
hardware version for vmwarewin7-MSProjectWin76474-v3.vmdk: '7'
2011-07-15
14:00:49|20773|455:421|new|VMware.pm:get_vm_virtual_hardware_version(3120)|retrieved
hardware version from api object: 7
2011-07-15
14:00:49|20773|455:421|new|VMware.pm:get_vm_virtual_hardware_version(3158)|returning
hardware version: 7
2011-07-15
14:00:49|20773|455:421|new|Linux.pm:create_directory(1475)|directory
either created or already exists on blade12:
'/vmfs/volumes/local-datastore/vm1202_74-v3'
2011-07-15 14:00:49|20773|455:421|new|VMware.pm:prepare_vmx(1222)|vm info:
|20773|455:421|new| display name: vm1202:vmwarewin7-MSProjectWin76474-v3
(nonpersistent)
|20773|455:421|new| image ID: 74
|20773|455:421|new| imagerevision ID: 81
|20773|455:421|new| vmx path:
/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
|20773|455:421|new| vmx directory name: vm1202_74-v3
|20773|455:421|new| vmx directory path:
/vmfs/volumes/local-datastore/vm1202_74-v3
|20773|455:421|new| vmdk file path:
/vmfs/volumes/nfs-datastore/vmwarewin7-MSProjectWin76474-v3/vmwarewin7-MSProjectWin76474-v3.vmdk
|20773|455:421|new| persistent: 0
|20773|455:421|new| computer ID: 13
|20773|455:421|new| computer name: vm1202
|20773|455:421|new| image name: vmwarewin7-MSProjectWin76474-v3
|20773|455:421|new| guest OS: winvista
|20773|455:421|new| virtual hardware version: 7
|20773|455:421|new| RAM: 4096
|20773|455:421|new| CPU count: 2
|20773|455:421|new| ethernet adapter type: e1000
|20773|455:421|new| virtual switch 0: Private
|20773|455:421|new| eth0 MAC address: 00:50:56:12:02:01
|20773|455:421|new| virtual switch 1: Public
|20773|455:421|new| eth1 MAC address: 00:50:56:12:02:02
|20773|455:421|new| disk adapter type: LsiLogic
|20773|455:421|new| disk mode: independent-nonpersistent
|20773|455:421|new| disk write through: FALSE
2011-07-15 14:00:49|20773|455:421|new|VMware.pm:prepare_vmx(1386)|image
project is: vcl, additional network adapters will not be configured
2011-07-15 14:00:49|20773|455:421|new|VMware.pm:prepare_vmx(1389)|vmx
parameters:
|20773|455:421|new| : {
|20773|455:421|new| : "#computer_id" => 13,
|20773|455:421|new| : "#image_id" => 74,
|20773|455:421|new| : "#imagerevision_id" => 81,
|20773|455:421|new| : ".encoding" => "UTF-8",
|20773|455:421|new| : "config.version" => 8,
|20773|455:421|new| : "disk.locking" => "false",
|20773|455:421|new| : "displayName" =>
"vm1202:vmwarewin7-MSProjectWin76474-v3 (nonpersistent)",
|20773|455:421|new| : "ethernet0.address" => "00:50:56:12:02:01",
|20773|455:421|new| : "ethernet0.addressType" => "static",
|20773|455:421|new| : "ethernet0.networkName" => "Private",
|20773|455:421|new| : "ethernet0.present" => "TRUE",
|20773|455:421|new| : "ethernet0.virtualDev" => "e1000",
|20773|455:421|new| : "ethernet1.address" => "00:50:56:12:02:02",
|20773|455:421|new| : "ethernet1.addressType" => "static",
|20773|455:421|new| : "ethernet1.networkName" => "Public",
|20773|455:421|new| : "ethernet1.present" => "TRUE",
|20773|455:421|new| : "ethernet1.virtualDev" => "e1000",
|20773|455:421|new| : "floppy0.present" => "FALSE",
|20773|455:421|new| : "guestOS" => "winvista",
|20773|455:421|new| : "gui.exitOnCLIHLT" => "TRUE",
|20773|455:421|new| : "memsize" => 4096,
|20773|455:421|new| : "msg.autoAnswer" => "TRUE",
|20773|455:421|new| : "numvcpus" => 2,
|20773|455:421|new| : "pciBridge0.present" => "TRUE",
|20773|455:421|new| : "pciBridge4.functions" => 8,
|20773|455:421|new| : "pciBridge4.present" => "TRUE",
|20773|455:421|new| : "pciBridge4.virtualDev" => "pcieRootPort",
|20773|455:421|new| : "pciBridge5.functions" => 8,
|20773|455:421|new| : "pciBridge5.present" => "TRUE",
|20773|455:421|new| : "pciBridge5.virtualDev" => "pcieRootPort",
|20773|455:421|new| : "pciBridge6.functions" => 8,
|20773|455:421|new| : "pciBridge6.present" => "TRUE",
|20773|455:421|new| : "pciBridge6.virtualDev" => "pcieRootPort",
|20773|455:421|new| : "pciBridge7.functions" => 8,
|20773|455:421|new| : "pciBridge7.present" => "TRUE",
|20773|455:421|new| : "pciBridge7.virtualDev" => "pcieRootPort",
|20773|455:421|new| : "powerType.powerOff" => "soft",
|20773|455:421|new| : "powerType.powerOn" => "hard",
|20773|455:421|new| : "powerType.reset" => "soft",
|20773|455:421|new| : "powerType.suspend" => "hard",
|20773|455:421|new| : "scsi0.present" => "TRUE",
|20773|455:421|new| : "scsi0.virtualDev" => "LsiLogic",
|20773|455:421|new| : "scsi0:0.fileName" =>
"/vmfs/volumes/nfs-datastore/vmwarewin7-MSProjectWin76474-v3/vmwarewin7-MSProjectWin76474-v3.vmdk",
|20773|455:421|new| : "scsi0:0.mode" => "independent-nonpersistent",
|20773|455:421|new| : "scsi0:0.present" => "TRUE",
|20773|455:421|new| : "scsi0:0.writeThrough" => "FALSE",
|20773|455:421|new| : "snapshot.disabled" => "TRUE",
|20773|455:421|new| : "svga.vramSize" => 33554432,
|20773|455:421|new| : "toolScripts.afterPowerOn" => "TRUE",
|20773|455:421|new| : "toolScripts.afterResume" => "TRUE",
|20773|455:421|new| : "toolScripts.beforePowerOff" => "TRUE",
|20773|455:421|new| : "toolScripts.beforeSuspend" => "TRUE",
|20773|455:421|new| : "tools.remindInstall" => "TRUE",
|20773|455:421|new| : "tools.syncTime" => "FALSE",
|20773|455:421|new| : "uuid.action" => "keep",
|20773|455:421|new| : "virtualHW.version" => 7,
|20773|455:421|new| : "vmci0.present" => "TRUE"
|20773|455:421|new| : }
2011-07-15 14:00:49|20773|455:421|new|VMware.pm:prepare_vmx(1400)|created
temporary vmx file: /tmp/vm1202_74-v3.vmx
2011-07-15
14:00:49|20773|455:421|new|Linux.pm:create_directory(1475)|directory
either created or already exists on blade12:
'/vmfs/volumes/local-datastore/vm1202_74-v3'
2011-07-15
14:00:49|20773|455:421|new|utils.pm:run_scp_command(5671)|attempt 1/3:
executing SCP command: /usr/bin/scp -B -i /etc/vcl/vcl.key -P 22 -p -r
/tmp/vm1202_74-v3.vmx
blade12:"/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx" 2>&1
2011-07-15 14:00:50|20773|455:421|new|utils.pm:run_scp_command(5722)|scp
successful: attempt 1/3, exit status: 0, output:
2011-07-15 14:00:50|20773|455:421|new|Linux.pm:copy_file_to(1740)|copied
file from management node to blade12: '/tmp/vm1202_74-v3.vmx' -->
blade12:'/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx'
2011-07-15 14:00:50|20773|455:421|new|VMware.pm:prepare_vmx(1409)|created
vmx file on VM host:
/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15 14:00:50|20773|455:421|new|VMware.pm:prepare_vmx(1412)|deleted
temporary vmx file: /tmp/vm1202_74-v3.vmx
2011-07-15
14:00:50|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, vmsetupconfig, prepared vmx file
2011-07-15 14:00:50|20773|455:421|new|VMware.pm:is_vm_registered(2788)|VM
is not registered:
'/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx', registered
paths:
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1206_74-v3/vm1206_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1203_74-v3/vm1203_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1204_74-v3/vm1204_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1205_74-v3/vm1205_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1201_74-v3/vm1201_74-v3.vmx
2011-07-15 14:00:52|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:00:52
2011-07-15 14:00:53|20773|455:421|new|VMware.pm:is_vm_registered(2783)|VM
is registered: /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15
14:00:53|20773|455:421|new|VIM_SSH.pm:vm_register(1172)|registered VM:
'/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx'
2011-07-15
14:00:53|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:00:53|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15 14:00:57|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:00:57
2011-07-15
14:00:58|20773|455:421|new|VIM_SSH.pm:_wait_for_task(830)|checking status
of task: haTask-3792-vim.VirtualMachine.powerOn-20780
2011-07-15
14:00:58|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:00:58|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15 14:00:58|20773|455:421|new|VIM_SSH.pm:_wait_for_task(843)|task
completed successfully: haTask-3792-vim.VirtualMachine.powerOn-20780
2011-07-15 14:00:58|20773|455:421|new|VIM_SSH.pm:vm_power_on(1037)|powered
on VM: /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15
14:00:58|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, startvm, registered and powered on vm1202
2011-07-15
14:00:58|20773|455:421|new|Version_6.pm:post_load(185)|beginning Windows
version 6 post-load tasks
2011-07-15 14:00:58|20773|455:421|new|Version_6.pm:post_load(193)|calling
parent class post_load() subroutine
2011-07-15 14:00:58|20773|455:421|new|Windows.pm:post_load(550)|beginning
Windows post-load tasks on vm1202
2011-07-15 14:00:59|20773|455:421|new|utils.pm:nmap_port(2707)|port 22 is
closed on vm1202
2011-07-15 14:00:59|20773|455:421|new|utils.pm:nmap_port(2707)|port 24 is
closed on vm1202
2011-07-15 14:00:59|20773|455:421|new|OS.pm:is_ssh_responding(416)|vm1202
is NOT responding to SSH, ports 22 or 24 are both closed
2011-07-15 14:00:59|20773|455:421|new|OS.pm:wait_for_response(477)|waiting
15 seconds for vm1202 to boot
2011-07-15 14:01:02|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:01:02
2011-07-15
14:01:03|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:03|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:03|20723|454:420|reserved|reserved.pm:process(243)|attempt 10 of
180, user has not acknowleged
2011-07-15 14:01:07|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:01:07
2011-07-15
14:01:08|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:08|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15 14:01:12|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:01:12
2011-07-15
14:01:13|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:13|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15 14:01:14|20773|455:421|new|OS.pm:wait_for_response(479)|waited
15 seconds for vm1202 to boot
2011-07-15 14:01:14|20773|455:421|new|OS.pm:wait_for_response(483)|waiting
for vm1202 to respond to SSH, maximum of 300 seconds
2011-07-15
14:01:14|20773|455:421|new|Module.pm:code_loop_timeout(396)|waiting for
vm1202 to respond to SSH, maximum of 300 seconds
2011-07-15
14:01:14|20773|455:421|new|Module.pm:code_loop_timeout(413)|attempt 1:
waiting for vm1202 to respond to SSH
2011-07-15 14:01:14|20773|455:421|new|utils.pm:nmap_port(2707)|port 22 is
closed on vm1202
2011-07-15 14:01:14|20773|455:421|new|utils.pm:nmap_port(2707)|port 24 is
closed on vm1202
2011-07-15 14:01:14|20773|455:421|new|OS.pm:is_ssh_responding(416)|vm1202
is NOT responding to SSH, ports 22 or 24 are both closed
2011-07-15
14:01:14|20773|455:421|new|Module.pm:code_loop_timeout(409)|attempt 1:
code returned false, seconds elapsed/remaining: 0/300, sleeping for 15
seconds
2011-07-15 14:01:17|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:01:17
2011-07-15
14:01:18|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:18|20495|453:419|reserved|reserved.pm:process(243)|attempt 20 of
180, user has not acknowleged
2011-07-15
14:01:18|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15 14:01:22|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:01:22
2011-07-15
14:01:23|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:23|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15 14:01:27|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:01:27
2011-07-15
14:01:28|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:28|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:29|20773|455:421|new|Module.pm:code_loop_timeout(413)|attempt 2:
waiting for vm1202 to respond to SSH
2011-07-15 14:01:30|20773|455:421|new|utils.pm:nmap_port(2707)|port 22 is
closed on vm1202
2011-07-15 14:01:30|20773|455:421|new|utils.pm:nmap_port(2707)|port 24 is
closed on vm1202
2011-07-15 14:01:30|20773|455:421|new|OS.pm:is_ssh_responding(416)|vm1202
is NOT responding to SSH, ports 22 or 24 are both closed
2011-07-15
14:01:30|20773|455:421|new|Module.pm:code_loop_timeout(409)|attempt 2:
code returned false, seconds elapsed/remaining: 16/284, sleeping for 15
seconds
2011-07-15 14:01:32|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:01:32
2011-07-15
14:01:33|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:33|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15 14:01:37|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:01:37
2011-07-15
14:01:38|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:38|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15 14:01:42|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:01:42
2011-07-15
14:01:43|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:43|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:45|20773|455:421|new|Module.pm:code_loop_timeout(413)|attempt 3:
waiting for vm1202 to respond to SSH
2011-07-15 14:01:45|20773|455:421|new|utils.pm:nmap_port(2707)|port 22 is
closed on vm1202
2011-07-15 14:01:45|20773|455:421|new|utils.pm:nmap_port(2707)|port 24 is
closed on vm1202
2011-07-15 14:01:45|20773|455:421|new|OS.pm:is_ssh_responding(416)|vm1202
is NOT responding to SSH, ports 22 or 24 are both closed
2011-07-15
14:01:45|20773|455:421|new|Module.pm:code_loop_timeout(409)|attempt 3:
code returned false, seconds elapsed/remaining: 31/269, sleeping for 15
seconds
Roger Herling
Sr. Desktop Administrator
Marist College
Office: 845-575-3347
Cell: 845-240-4298
From: Andy Kurth <an...@ncsu.edu>
To: vcl-user@incubator.apache.org
Date: 07/15/2011 01:44 PM
Subject: Re: why does it take so long to provision a VM that
already has the correct image on it?
Hi Roger,
Can you send the vcld.log output for a reservation that should have been
preloaded but reloaded anyway.
-Andy
On Fri, Jul 15, 2011 at 12:20 PM, Roger Herling <Ro...@marist.edu>
wrote:
To be more precise Vmware esx local and network storage
Roger Herling
Sr. Desktop Administrator
Marist College
Office: 845-575-3347
Cell: 845-240-4298
From: Aaron Peeler <fa...@ncsu.edu>
To: vcl-user@incubator.apache.org
Date: 07/15/2011 12:17 PM
Subject: Re: why does it take so long to provision a VM that
already has the correct image on it?
Hello Roger,
Which provisioning module are you using for your vms? In an older release,
there was a esx.pm module which has this behavior.
Make sure your not using that prov module.
Aaron
On Fri, Jul 15, 2011 at 11:59 AM, Roger Herling <Ro...@marist.edu>
wrote:
Hi all we have been having an issue where all of our vm's are pre loaded
with an image but when you request a reservation the VM is deleted and
reset why is this happening. I thought that the whole purpose of having
the vms ready to go was that provisioning time should only be 1-2 minutes
instead it 5-7.
Roger Herling
Sr. Desktop Administrator
Marist College
Office: 845-575-3347
Cell: 845-240-4298
--
Aaron Peeler
Program Manager
Virtual Computing Lab
NC State University
All electronic mail messages in connection with State business which are
sent to or received by this account are subject to the NC Public Records
Law and may be disclosed to third parties.
Re: why does it take so long to provision a VM that already has the correct
image on it?
Posted by Roger Herling <Ro...@marist.edu>.
Hey Andy here you go. I was able to get two Vms to provision within
45seconds but those where two that had just been reloaded 10 minutes
earlier. It appears to only happen when a machine is idle for a while.
{421}{computer}{state}{name}
|20773|455:421|new| computer_state_name = available
2011-07-15
14:00:28|20773|455:421|new|utils.pm:get_management_node_id(8740)|environment
variable: 1
2011-07-15 14:00:28|20773|455:421|new|new.pm:process(133)|reservation is
parent = 1
2011-07-15 14:00:28|20773|455:421|new|new.pm:process(134)|preload only = 0
2011-07-15 14:00:28|20773|455:421|new|new.pm:process(135)|originating
request state = new
2011-07-15 14:00:28|20773|455:421|new|new.pm:process(136)|originating
request laststate = new
2011-07-15 14:00:28|20773|455:421|new|new.pm:process(137)|originating
computer state = available
2011-07-15 14:00:28|20773|455:421|new|new.pm:process(138)|originating
computer type = virtualmachine
2011-07-15
14:00:28|20773|455:421|new|DataStructure.pm:is_parent_reservation(943)|returning
true: parent reservation ID for this request: 421
2011-07-15
14:00:28|20773|455:421|new|DataStructure.pm:get_computer_state_name(2227)|attempting
to retrieve current state of computer vm1202 from the database
2011-07-15
14:00:28|20773|455:421|new|DataStructure.pm:get_computer_state_name(2258)|retrieved
current state of computer vm1202 from the database: available
2011-07-15
14:00:28|20773|455:421|new|DataStructure.pm:_automethod(786)|data
structure updated:
$self->request_data->{reservation}{421}{computer}{state}{name}
|20773|455:421|new| computer_state_name = available
2011-07-15
14:00:28|20773|455:421|new|utils.pm:get_management_node_id(8740)|environment
variable: 1
2011-07-15
14:00:28|20773|455:421|new|new.pm:computer_not_being_used(787)|vm1202
state is available
2011-07-15
14:00:28|20773|455:421|new|new.pm:computer_not_being_used(797)|vm1202 is
available, its state is available
2011-07-15 14:00:28|20773|455:421|new|new.pm:process(186)|vm1202 is not
being used
2011-07-15
14:00:28|20773|455:421|new|DataStructure.pm:is_parent_reservation(943)|returning
true: parent reservation ID for this request: 421
2011-07-15
14:00:28|20773|455:421|new|DataStructure.pm:get_computer_state_name(2227)|attempting
to retrieve current state of computer vm1202 from the database
2011-07-15
14:00:28|20773|455:421|new|DataStructure.pm:get_computer_state_name(2258)|retrieved
current state of computer vm1202 from the database: available
2011-07-15
14:00:28|20773|455:421|new|DataStructure.pm:_automethod(786)|data
structure updated:
$self->request_data->{reservation}{421}{computer}{state}{name}
|20773|455:421|new| computer_state_name = available
2011-07-15
14:00:28|20773|455:421|new|utils.pm:get_management_node_id(8740)|environment
variable: 1
2011-07-15 14:00:28|20773|455:421|new|new.pm:reload_image(529)|calling
VCL::Module::Provisioning::VMware::VMware->node_status()
2011-07-15
14:00:29|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, statuscheck, checking status of node
2011-07-15 14:00:29|20773|455:421|new|utils.pm:nmap_port(2707)|port 22 is
closed on vm1202
2011-07-15 14:00:29|20773|455:421|new|utils.pm:nmap_port(2707)|port 24 is
closed on vm1202
2011-07-15 14:00:29|20773|455:421|new|OS.pm:is_ssh_responding(416)|vm1202
is NOT responding to SSH, ports 22 or 24 are both closed
2011-07-15 14:00:29|20773|455:421|new|VMware.pm:node_status(738)|VM vm1202
is not responding to SSH, returning 'RELOAD'
2011-07-15 14:00:29|20773|455:421|new|new.pm:reload_image(544)|node_status
returned a hash reference
2011-07-15 14:00:29|20773|455:421|new|new.pm:reload_image(549)|node_status
hash reference contains key {status}=RELOAD
2011-07-15 14:00:29|20773|455:421|new|new.pm:reload_image(624)|node status
is RELOAD, vm1202 will be reloaded
2011-07-15
14:00:29|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, loadimageblade, vm1202 must be reloaded with
vmwarewin7-MSProjectWin76474-v3
2011-07-15 14:00:29|20773|455:421|new|new.pm:reload_image(638)|calling
VCL::Module::Provisioning::VMware::VMware->does_image_exist()
2011-07-15
14:00:29|20773|455:421|new|VMware.pm:does_image_exist(2937)|image exists
in the non-persistent directory on the VM host:
/vmfs/volumes/nfs-datastore/vmwarewin7-MSProjectWin76474-v3/vmwarewin7-MSProjectWin76474-v3.vmdk
2011-07-15
14:00:29|20773|455:421|new|new.pm:reload_image(641)|vmwarewin7-MSProjectWin76474-v3
exists on this management node
2011-07-15
14:00:29|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, doesimageexists, confirmed image exists
2011-07-15
14:00:29|20773|455:421|new|utils.pm:update_computer_state(2091)|computer
13 state updated to: reloading
2011-07-15 14:00:29|20773|455:421|new|new.pm:reload_image(674)|computer
vm1202 state set to reloading
2011-07-15
14:00:29|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, info, computer state updated to reloading
2011-07-15 14:00:29|20773|455:421|new|new.pm:reload_image(685)|calling
VCL::Module::Provisioning::VMware::VMware->load() subroutine
2011-07-15
14:00:29|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, info, calling
VCL::Module::Provisioning::VMware::VMware->load() subroutine
2011-07-15
14:00:29|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, doesimageexists, image exists vmwarewin7-MSProjectWin76474-v3
2011-07-15
14:00:29|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, startload, vm1202 vmwarewin7-MSProjectWin76474-v3
2011-07-15
14:00:29|20773|455:421|new|VMware.pm:get_vmx_file_paths(3333)|attempting
to find existing vmx files on the VM host
2011-07-15 14:00:29|20773|455:421|new|Linux.pm:find_files(1933)|attempting
to find files on blade12, base directory path:
'/vmfs/volumes/local-datastore/', pattern: *.vmx, command: find
"/vmfs/volumes/local-datastore/" -type f -iname "*.vmx"
2011-07-15 14:00:30|20773|455:421|new|Linux.pm:find_files(1951)|matching
file count: 7
2011-07-15
14:00:31|20773|455:421|new|VMware.pm:get_vmx_file_paths(3344)|found 7
unique vmx files on VM host:
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1201_74-v3/vm1201_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1203_74-v3/vm1203_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1204_74-v3/vm1204_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1205_74-v3/vm1205_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1206_74-v3/vm1206_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1206_cs5fix/vm1206_cs5fix.vmx
2011-07-15
14:00:31|20773|455:421|new|VMware.pm:remove_existing_vms(1129)|ignoring
existing vmx directory: vm1201_74-v3
2011-07-15
14:00:31|20773|455:421|new|VMware.pm:remove_existing_vms(1114)|found
existing vmx directory with that appears to match vm1202:
/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15
14:00:31|20773|455:421|new|VMware.pm:get_vmx_info(3403)|attempting to
retrieve info from vmx file:
/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15
14:00:31|20773|455:421|new|Linux.pm:get_file_contents(1576)|retrieved 88
lines from file on blade12:
'/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx'
2011-07-15 14:00:31|20773|455:421|new|VMware.pm:delete_vm(3510)|attempting
to delete VM: /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15
14:00:31|20773|455:421|new|VMware.pm:get_vmx_info(3399)|returning
previously retrieved info from vmx file:
/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15 14:00:32|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:00:32
2011-07-15 14:00:32|20773|455:421|new|VMware.pm:is_vm_registered(2783)|VM
is registered: /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15
14:00:33|20773|455:421|new|VIM_SSH.pm:get_vm_power_state(954)|VM is
powered on: /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15
14:00:33|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:00:33|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15 14:00:37|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:00:37
2011-07-15
14:00:38|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:00:38|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:00:40|20773|455:421|new|VIM_SSH.pm:_wait_for_task(830)|checking status
of task: haTask-3456-vim.VirtualMachine.powerOff-20732
2011-07-15 14:00:40|20773|455:421|new|VIM_SSH.pm:_wait_for_task(843)|task
completed successfully: haTask-3456-vim.VirtualMachine.powerOff-20732
2011-07-15
14:00:40|20773|455:421|new|VIM_SSH.pm:vm_power_off(1112)|powered off VM:
/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15 14:00:42|20773|455:421|new|VMware.pm:is_vm_registered(2788)|VM
is not registered:
'/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx', registered
paths:
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1206_74-v3/vm1206_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1203_74-v3/vm1203_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1204_74-v3/vm1204_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1205_74-v3/vm1205_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1201_74-v3/vm1201_74-v3.vmx
2011-07-15
14:00:42|20773|455:421|new|VIM_SSH.pm:vm_unregister(1244)|unregistered VM:
/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx (ID: 3456)
2011-07-15 14:00:42|20773|455:421|new|VMware.pm:delete_vm(3533)|checking
if existing VM's vmdk file should be deleted:
|20773|455:421|new| vmdk file path:
/vmfs/volumes/nfs-datastore/vmwarewin7-MSProjectWin76474-v3/vmwarewin7-MSProjectWin76474-v3.vmdk
|20773|455:421|new| vmx storage identier key: scsi0:0
|20773|455:421|new| disk mode: independent-nonpersistent
2011-07-15 14:00:42|20773|455:421|new|VMware.pm:delete_vm(3543)|mode of
vmdk file: independent-nonpersistent, vmdk directory will NOT be deleted
2011-07-15 14:00:42|20773|455:421|new|VMware.pm:delete_vm(3556)|attempt
1/5: attempting to delete vmx directory:
/vmfs/volumes/local-datastore/vm1202_74-v3
2011-07-15 14:00:42|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:00:42
2011-07-15 14:00:42|20773|455:421|new|Linux.pm:delete_file(1410)|deleted
'/vmfs/volumes/local-datastore/vm1202_74-v3' on blade12
2011-07-15 14:00:43|20773|455:421|new|Linux.pm:file_exists(1341)|file or
directory does not exist on blade12:
'/vmfs/volumes/local-datastore/vm1202_74-v3'
2011-07-15 14:00:43|20773|455:421|new|Linux.pm:delete_file(1424)|confirmed
file does not exist on blade12:
'/vmfs/volumes/local-datastore/vm1202_74-v3'
2011-07-15 14:00:43|20773|455:421|new|VMware.pm:delete_vm(3558)|deleted
VM: /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15
14:00:43|20773|455:421|new|VMware.pm:remove_existing_vms(1129)|ignoring
existing vmx directory: vm1203_74-v3
2011-07-15
14:00:43|20773|455:421|new|VMware.pm:remove_existing_vms(1129)|ignoring
existing vmx directory: vm1204_74-v3
2011-07-15
14:00:43|20773|455:421|new|VMware.pm:remove_existing_vms(1129)|ignoring
existing vmx directory: vm1205_74-v3
2011-07-15
14:00:43|20773|455:421|new|VMware.pm:remove_existing_vms(1129)|ignoring
existing vmx directory: vm1206_74-v3
2011-07-15
14:00:43|20773|455:421|new|VMware.pm:remove_existing_vms(1129)|ignoring
existing vmx directory: vm1206_cs5fix
2011-07-15
14:00:43|20773|455:421|new|VMware.pm:get_repository_vmdk_base_directory_path(2655)|repository
path is not set for the VM profile, using management node install path:
/install/vmware_images
2011-07-15
14:00:43|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:00:43|20773|455:421|new|VMware.pm:get_vmhost_product_name(4090)|VMware
product being used on VM host blade12: 'VMware ESXi 4.1.0 build-260247'
2011-07-15
14:00:43|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:00:44|20773|455:421|new|VIM_SSH.pm:_get_datastore_names(477)|retrieved
datastore names: local-datastore, nfs-datastore
2011-07-15
14:00:45|20773|455:421|new|VIM_SSH.pm:get_virtual_disk_type(1370)|vmwarewin7-MSProjectWin76474-v3.vmdk
disk type: FlatVer2
2011-07-15
14:00:45|20773|455:421|new|VMware.pm:check_vmdk_disk_type(1657)|flat
virtual disk (FlatVer2) does not need to be converted for VMware ESXi
4.1.0 build-260247
2011-07-15
14:00:45|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, transfervm, copied vmwarewin7-MSProjectWin76474-v3 to vm1202
2011-07-15
14:00:45|20773|455:421|new|VMware.pm:get_vm_os_configuration(3212)|retrieved
default VM configuration for OS: 7-x86
|20773|455:421|new| : {
|20773|455:421|new| : "ethernet-virtualDev" => "e1000",
|20773|455:421|new| : "guestOS" => "winvista",
|20773|455:421|new| : "scsi-virtualDev" => "lsiLogic"
|20773|455:421|new| : }
2011-07-15 14:00:47|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:00:47
2011-07-15
14:00:47|20773|455:421|new|VIM_SSH.pm:get_virtual_disk_controller_type(1521)|retrieved
controller type for vmwarewin7-MSProjectWin76474-v3.vmdk: 'LsiLogic'
2011-07-15
14:00:47|20773|455:421|new|VMware.pm:get_vm_disk_adapter_type(3073)|retrieved
VM disk adapter type from api object: LsiLogic
2011-07-15
14:00:48|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:00:48|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:00:49|20773|455:421|new|VIM_SSH.pm:get_virtual_disk_hardware_version(1669)|retrieved
hardware version for vmwarewin7-MSProjectWin76474-v3.vmdk: '7'
2011-07-15
14:00:49|20773|455:421|new|VMware.pm:get_vm_virtual_hardware_version(3120)|retrieved
hardware version from api object: 7
2011-07-15
14:00:49|20773|455:421|new|VMware.pm:get_vm_virtual_hardware_version(3158)|returning
hardware version: 7
2011-07-15
14:00:49|20773|455:421|new|Linux.pm:create_directory(1475)|directory
either created or already exists on blade12:
'/vmfs/volumes/local-datastore/vm1202_74-v3'
2011-07-15 14:00:49|20773|455:421|new|VMware.pm:prepare_vmx(1222)|vm info:
|20773|455:421|new| display name: vm1202:vmwarewin7-MSProjectWin76474-v3
(nonpersistent)
|20773|455:421|new| image ID: 74
|20773|455:421|new| imagerevision ID: 81
|20773|455:421|new| vmx path:
/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
|20773|455:421|new| vmx directory name: vm1202_74-v3
|20773|455:421|new| vmx directory path:
/vmfs/volumes/local-datastore/vm1202_74-v3
|20773|455:421|new| vmdk file path:
/vmfs/volumes/nfs-datastore/vmwarewin7-MSProjectWin76474-v3/vmwarewin7-MSProjectWin76474-v3.vmdk
|20773|455:421|new| persistent: 0
|20773|455:421|new| computer ID: 13
|20773|455:421|new| computer name: vm1202
|20773|455:421|new| image name: vmwarewin7-MSProjectWin76474-v3
|20773|455:421|new| guest OS: winvista
|20773|455:421|new| virtual hardware version: 7
|20773|455:421|new| RAM: 4096
|20773|455:421|new| CPU count: 2
|20773|455:421|new| ethernet adapter type: e1000
|20773|455:421|new| virtual switch 0: Private
|20773|455:421|new| eth0 MAC address: 00:50:56:12:02:01
|20773|455:421|new| virtual switch 1: Public
|20773|455:421|new| eth1 MAC address: 00:50:56:12:02:02
|20773|455:421|new| disk adapter type: LsiLogic
|20773|455:421|new| disk mode: independent-nonpersistent
|20773|455:421|new| disk write through: FALSE
2011-07-15 14:00:49|20773|455:421|new|VMware.pm:prepare_vmx(1386)|image
project is: vcl, additional network adapters will not be configured
2011-07-15 14:00:49|20773|455:421|new|VMware.pm:prepare_vmx(1389)|vmx
parameters:
|20773|455:421|new| : {
|20773|455:421|new| : "#computer_id" => 13,
|20773|455:421|new| : "#image_id" => 74,
|20773|455:421|new| : "#imagerevision_id" => 81,
|20773|455:421|new| : ".encoding" => "UTF-8",
|20773|455:421|new| : "config.version" => 8,
|20773|455:421|new| : "disk.locking" => "false",
|20773|455:421|new| : "displayName" =>
"vm1202:vmwarewin7-MSProjectWin76474-v3 (nonpersistent)",
|20773|455:421|new| : "ethernet0.address" => "00:50:56:12:02:01",
|20773|455:421|new| : "ethernet0.addressType" => "static",
|20773|455:421|new| : "ethernet0.networkName" => "Private",
|20773|455:421|new| : "ethernet0.present" => "TRUE",
|20773|455:421|new| : "ethernet0.virtualDev" => "e1000",
|20773|455:421|new| : "ethernet1.address" => "00:50:56:12:02:02",
|20773|455:421|new| : "ethernet1.addressType" => "static",
|20773|455:421|new| : "ethernet1.networkName" => "Public",
|20773|455:421|new| : "ethernet1.present" => "TRUE",
|20773|455:421|new| : "ethernet1.virtualDev" => "e1000",
|20773|455:421|new| : "floppy0.present" => "FALSE",
|20773|455:421|new| : "guestOS" => "winvista",
|20773|455:421|new| : "gui.exitOnCLIHLT" => "TRUE",
|20773|455:421|new| : "memsize" => 4096,
|20773|455:421|new| : "msg.autoAnswer" => "TRUE",
|20773|455:421|new| : "numvcpus" => 2,
|20773|455:421|new| : "pciBridge0.present" => "TRUE",
|20773|455:421|new| : "pciBridge4.functions" => 8,
|20773|455:421|new| : "pciBridge4.present" => "TRUE",
|20773|455:421|new| : "pciBridge4.virtualDev" => "pcieRootPort",
|20773|455:421|new| : "pciBridge5.functions" => 8,
|20773|455:421|new| : "pciBridge5.present" => "TRUE",
|20773|455:421|new| : "pciBridge5.virtualDev" => "pcieRootPort",
|20773|455:421|new| : "pciBridge6.functions" => 8,
|20773|455:421|new| : "pciBridge6.present" => "TRUE",
|20773|455:421|new| : "pciBridge6.virtualDev" => "pcieRootPort",
|20773|455:421|new| : "pciBridge7.functions" => 8,
|20773|455:421|new| : "pciBridge7.present" => "TRUE",
|20773|455:421|new| : "pciBridge7.virtualDev" => "pcieRootPort",
|20773|455:421|new| : "powerType.powerOff" => "soft",
|20773|455:421|new| : "powerType.powerOn" => "hard",
|20773|455:421|new| : "powerType.reset" => "soft",
|20773|455:421|new| : "powerType.suspend" => "hard",
|20773|455:421|new| : "scsi0.present" => "TRUE",
|20773|455:421|new| : "scsi0.virtualDev" => "LsiLogic",
|20773|455:421|new| : "scsi0:0.fileName" =>
"/vmfs/volumes/nfs-datastore/vmwarewin7-MSProjectWin76474-v3/vmwarewin7-MSProjectWin76474-v3.vmdk",
|20773|455:421|new| : "scsi0:0.mode" => "independent-nonpersistent",
|20773|455:421|new| : "scsi0:0.present" => "TRUE",
|20773|455:421|new| : "scsi0:0.writeThrough" => "FALSE",
|20773|455:421|new| : "snapshot.disabled" => "TRUE",
|20773|455:421|new| : "svga.vramSize" => 33554432,
|20773|455:421|new| : "toolScripts.afterPowerOn" => "TRUE",
|20773|455:421|new| : "toolScripts.afterResume" => "TRUE",
|20773|455:421|new| : "toolScripts.beforePowerOff" => "TRUE",
|20773|455:421|new| : "toolScripts.beforeSuspend" => "TRUE",
|20773|455:421|new| : "tools.remindInstall" => "TRUE",
|20773|455:421|new| : "tools.syncTime" => "FALSE",
|20773|455:421|new| : "uuid.action" => "keep",
|20773|455:421|new| : "virtualHW.version" => 7,
|20773|455:421|new| : "vmci0.present" => "TRUE"
|20773|455:421|new| : }
2011-07-15 14:00:49|20773|455:421|new|VMware.pm:prepare_vmx(1400)|created
temporary vmx file: /tmp/vm1202_74-v3.vmx
2011-07-15
14:00:49|20773|455:421|new|Linux.pm:create_directory(1475)|directory
either created or already exists on blade12:
'/vmfs/volumes/local-datastore/vm1202_74-v3'
2011-07-15
14:00:49|20773|455:421|new|utils.pm:run_scp_command(5671)|attempt 1/3:
executing SCP command: /usr/bin/scp -B -i /etc/vcl/vcl.key -P 22 -p -r
/tmp/vm1202_74-v3.vmx
blade12:"/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx" 2>&1
2011-07-15 14:00:50|20773|455:421|new|utils.pm:run_scp_command(5722)|scp
successful: attempt 1/3, exit status: 0, output:
2011-07-15 14:00:50|20773|455:421|new|Linux.pm:copy_file_to(1740)|copied
file from management node to blade12: '/tmp/vm1202_74-v3.vmx' -->
blade12:'/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx'
2011-07-15 14:00:50|20773|455:421|new|VMware.pm:prepare_vmx(1409)|created
vmx file on VM host:
/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15 14:00:50|20773|455:421|new|VMware.pm:prepare_vmx(1412)|deleted
temporary vmx file: /tmp/vm1202_74-v3.vmx
2011-07-15
14:00:50|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, vmsetupconfig, prepared vmx file
2011-07-15 14:00:50|20773|455:421|new|VMware.pm:is_vm_registered(2788)|VM
is not registered:
'/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx', registered
paths:
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1206_74-v3/vm1206_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1203_74-v3/vm1203_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1204_74-v3/vm1204_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1205_74-v3/vm1205_74-v3.vmx
|20773|455:421|new|
/vmfs/volumes/local-datastore/vm1201_74-v3/vm1201_74-v3.vmx
2011-07-15 14:00:52|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:00:52
2011-07-15 14:00:53|20773|455:421|new|VMware.pm:is_vm_registered(2783)|VM
is registered: /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15
14:00:53|20773|455:421|new|VIM_SSH.pm:vm_register(1172)|registered VM:
'/vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx'
2011-07-15
14:00:53|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:00:53|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15 14:00:57|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:00:57
2011-07-15
14:00:58|20773|455:421|new|VIM_SSH.pm:_wait_for_task(830)|checking status
of task: haTask-3792-vim.VirtualMachine.powerOn-20780
2011-07-15
14:00:58|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:00:58|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15 14:00:58|20773|455:421|new|VIM_SSH.pm:_wait_for_task(843)|task
completed successfully: haTask-3792-vim.VirtualMachine.powerOn-20780
2011-07-15 14:00:58|20773|455:421|new|VIM_SSH.pm:vm_power_on(1037)|powered
on VM: /vmfs/volumes/local-datastore/vm1202_74-v3/vm1202_74-v3.vmx
2011-07-15
14:00:58|20773|455:421|new|utils.pm:insertloadlog(3933)|inserted
computer=13, startvm, registered and powered on vm1202
2011-07-15
14:00:58|20773|455:421|new|Version_6.pm:post_load(185)|beginning Windows
version 6 post-load tasks
2011-07-15 14:00:58|20773|455:421|new|Version_6.pm:post_load(193)|calling
parent class post_load() subroutine
2011-07-15 14:00:58|20773|455:421|new|Windows.pm:post_load(550)|beginning
Windows post-load tasks on vm1202
2011-07-15 14:00:59|20773|455:421|new|utils.pm:nmap_port(2707)|port 22 is
closed on vm1202
2011-07-15 14:00:59|20773|455:421|new|utils.pm:nmap_port(2707)|port 24 is
closed on vm1202
2011-07-15 14:00:59|20773|455:421|new|OS.pm:is_ssh_responding(416)|vm1202
is NOT responding to SSH, ports 22 or 24 are both closed
2011-07-15 14:00:59|20773|455:421|new|OS.pm:wait_for_response(477)|waiting
15 seconds for vm1202 to boot
2011-07-15 14:01:02|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:01:02
2011-07-15
14:01:03|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:03|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:03|20723|454:420|reserved|reserved.pm:process(243)|attempt 10 of
180, user has not acknowleged
2011-07-15 14:01:07|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:01:07
2011-07-15
14:01:08|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:08|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15 14:01:12|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:01:12
2011-07-15
14:01:13|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:13|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15 14:01:14|20773|455:421|new|OS.pm:wait_for_response(479)|waited
15 seconds for vm1202 to boot
2011-07-15 14:01:14|20773|455:421|new|OS.pm:wait_for_response(483)|waiting
for vm1202 to respond to SSH, maximum of 300 seconds
2011-07-15
14:01:14|20773|455:421|new|Module.pm:code_loop_timeout(396)|waiting for
vm1202 to respond to SSH, maximum of 300 seconds
2011-07-15
14:01:14|20773|455:421|new|Module.pm:code_loop_timeout(413)|attempt 1:
waiting for vm1202 to respond to SSH
2011-07-15 14:01:14|20773|455:421|new|utils.pm:nmap_port(2707)|port 22 is
closed on vm1202
2011-07-15 14:01:14|20773|455:421|new|utils.pm:nmap_port(2707)|port 24 is
closed on vm1202
2011-07-15 14:01:14|20773|455:421|new|OS.pm:is_ssh_responding(416)|vm1202
is NOT responding to SSH, ports 22 or 24 are both closed
2011-07-15
14:01:14|20773|455:421|new|Module.pm:code_loop_timeout(409)|attempt 1:
code returned false, seconds elapsed/remaining: 0/300, sleeping for 15
seconds
2011-07-15 14:01:17|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:01:17
2011-07-15
14:01:18|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:18|20495|453:419|reserved|reserved.pm:process(243)|attempt 20 of
180, user has not acknowleged
2011-07-15
14:01:18|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15 14:01:22|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:01:22
2011-07-15
14:01:23|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:23|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15 14:01:27|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:01:27
2011-07-15
14:01:28|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:28|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:29|20773|455:421|new|Module.pm:code_loop_timeout(413)|attempt 2:
waiting for vm1202 to respond to SSH
2011-07-15 14:01:30|20773|455:421|new|utils.pm:nmap_port(2707)|port 22 is
closed on vm1202
2011-07-15 14:01:30|20773|455:421|new|utils.pm:nmap_port(2707)|port 24 is
closed on vm1202
2011-07-15 14:01:30|20773|455:421|new|OS.pm:is_ssh_responding(416)|vm1202
is NOT responding to SSH, ports 22 or 24 are both closed
2011-07-15
14:01:30|20773|455:421|new|Module.pm:code_loop_timeout(409)|attempt 2:
code returned false, seconds elapsed/remaining: 16/284, sleeping for 15
seconds
2011-07-15 14:01:32|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:01:32
2011-07-15
14:01:33|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:33|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15 14:01:37|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:01:37
2011-07-15
14:01:38|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:38|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15 14:01:42|30621|vcld:main(166)|lastcheckin time updated for
management node 1: 2011-07-15 14:01:42
2011-07-15
14:01:43|20495|453:419|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:43|20723|454:420|reserved|DataStructure.pm:get_reservation_remote_ip(1045)|reservation
remote IP is not defined
2011-07-15
14:01:45|20773|455:421|new|Module.pm:code_loop_timeout(413)|attempt 3:
waiting for vm1202 to respond to SSH
2011-07-15 14:01:45|20773|455:421|new|utils.pm:nmap_port(2707)|port 22 is
closed on vm1202
2011-07-15 14:01:45|20773|455:421|new|utils.pm:nmap_port(2707)|port 24 is
closed on vm1202
2011-07-15 14:01:45|20773|455:421|new|OS.pm:is_ssh_responding(416)|vm1202
is NOT responding to SSH, ports 22 or 24 are both closed
2011-07-15
14:01:45|20773|455:421|new|Module.pm:code_loop_timeout(409)|attempt 3:
code returned false, seconds elapsed/remaining: 31/269, sleeping for 15
seconds
Roger Herling
Sr. Desktop Administrator
Marist College
Office: 845-575-3347
Cell: 845-240-4298
From: Andy Kurth <an...@ncsu.edu>
To: vcl-user@incubator.apache.org
Date: 07/15/2011 01:44 PM
Subject: Re: why does it take so long to provision a VM that
already has the correct image on it?
Hi Roger,
Can you send the vcld.log output for a reservation that should have been
preloaded but reloaded anyway.
-Andy
On Fri, Jul 15, 2011 at 12:20 PM, Roger Herling <Ro...@marist.edu>
wrote:
To be more precise Vmware esx local and network storage
Roger Herling
Sr. Desktop Administrator
Marist College
Office: 845-575-3347
Cell: 845-240-4298
From: Aaron Peeler <fa...@ncsu.edu>
To: vcl-user@incubator.apache.org
Date: 07/15/2011 12:17 PM
Subject: Re: why does it take so long to provision a VM that
already has the correct image on it?
Hello Roger,
Which provisioning module are you using for your vms? In an older release,
there was a esx.pm module which has this behavior.
Make sure your not using that prov module.
Aaron
On Fri, Jul 15, 2011 at 11:59 AM, Roger Herling <Ro...@marist.edu>
wrote:
Hi all we have been having an issue where all of our vm's are pre loaded
with an image but when you request a reservation the VM is deleted and
reset why is this happening. I thought that the whole purpose of having
the vms ready to go was that provisioning time should only be 1-2 minutes
instead it 5-7.
Roger Herling
Sr. Desktop Administrator
Marist College
Office: 845-575-3347
Cell: 845-240-4298
--
Aaron Peeler
Program Manager
Virtual Computing Lab
NC State University
All electronic mail messages in connection with State business which are
sent to or received by this account are subject to the NC Public Records
Law and may be disclosed to third parties.
Re: why does it take so long to provision a VM that already has the
correct image on it?
Posted by Andy Kurth <an...@ncsu.edu>.
Hi Roger,
Can you send the vcld.log output for a reservation that should have been
preloaded but reloaded anyway.
-Andy
On Fri, Jul 15, 2011 at 12:20 PM, Roger Herling <Ro...@marist.edu>wrote:
> To be more precise Vmware esx local and network storage
>
> *Roger Herling*
> *Sr. Desktop Administrator*
> Marist College
> *Office:* 845-575-3347
> *Cell:* 845-240-4298
>
>
>
>
>
> From: Aaron Peeler <fa...@ncsu.edu>
> To: vcl-user@incubator.apache.org
> Date: 07/15/2011 12:17 PM
> Subject: Re: why does it take so long to provision a VM that
> already has the correct image on it?
> ------------------------------
>
>
>
> Hello Roger,
>
> Which provisioning module are you using for your vms? In an older release,
> there was a *esx.pm* <http://esx.pm/> module which has this behavior.
>
> Make sure your not using that prov module.
> Aaron
>
> On Fri, Jul 15, 2011 at 11:59 AM, Roger Herling <*Roger.Herling@marist.edu
> * <Ro...@marist.edu>> wrote:
> Hi all we have been having an issue where all of our vm's are pre loaded
> with an image but when you request a reservation the VM is deleted and reset
> why is this happening. I thought that the whole purpose of having the vms
> ready to go was that provisioning time should only be 1-2 minutes instead it
> 5-7.
>
> *
> Roger Herling* *
> Sr. Desktop Administrator*
> Marist College *
> Office:* 845-575-3347 *
> Cell:* 845-240-4298
>
>
>
>
>
> --
> Aaron Peeler
> Program Manager
> Virtual Computing Lab
> NC State University
>
> All electronic mail messages in connection with State business which are
> sent to or received by this account are subject to the NC Public Records Law
> and may be disclosed to third parties.
>
Re: why does it take so long to provision a VM that already has the correct
image on it?
Posted by Roger Herling <Ro...@marist.edu>.
To be more precise Vmware esx local and network storage
Roger Herling
Sr. Desktop Administrator
Marist College
Office: 845-575-3347
Cell: 845-240-4298
From: Aaron Peeler <fa...@ncsu.edu>
To: vcl-user@incubator.apache.org
Date: 07/15/2011 12:17 PM
Subject: Re: why does it take so long to provision a VM that
already has the correct image on it?
Hello Roger,
Which provisioning module are you using for your vms? In an older release,
there was a esx.pm module which has this behavior.
Make sure your not using that prov module.
Aaron
On Fri, Jul 15, 2011 at 11:59 AM, Roger Herling <Ro...@marist.edu>
wrote:
Hi all we have been having an issue where all of our vm's are pre loaded
with an image but when you request a reservation the VM is deleted and
reset why is this happening. I thought that the whole purpose of having
the vms ready to go was that provisioning time should only be 1-2 minutes
instead it 5-7.
Roger Herling
Sr. Desktop Administrator
Marist College
Office: 845-575-3347
Cell: 845-240-4298
--
Aaron Peeler
Program Manager
Virtual Computing Lab
NC State University
All electronic mail messages in connection with State business which are
sent to or received by this account are subject to the NC Public Records
Law and may be disclosed to third parties.
Re: why does it take so long to provision a VM that already has the
correct image on it?
Posted by Aaron Peeler <fa...@ncsu.edu>.
Hello Roger,
Which provisioning module are you using for your vms? In an older release,
there was a esx.pm module which has this behavior.
Make sure your not using that prov module.
Aaron
On Fri, Jul 15, 2011 at 11:59 AM, Roger Herling <Ro...@marist.edu>wrote:
> Hi all we have been having an issue where all of our vm's are pre loaded
> with an image but when you request a reservation the VM is deleted and reset
> why is this happening. I thought that the whole purpose of having the vms
> ready to go was that provisioning time should only be 1-2 minutes instead it
> 5-7.
>
>
> *Roger Herling*
> *Sr. Desktop Administrator*
> Marist College
> *Office:* 845-575-3347
> *Cell:* 845-240-4298
>
>
--
Aaron Peeler
Program Manager
Virtual Computing Lab
NC State University
All electronic mail messages in connection with State business which are
sent to or received by this account are subject to the NC Public Records Law
and may be disclosed to third parties.